Skip to content

Commit d50fc9e

Browse files
blowfishproblowfishpro
committed
patch in background
Patches are now applied on a separate thread to an isolated copy of the game database, then copied into the actual game database by post-patch runner. Post patch runner will wait for patched database if it isn't done yet. One consequence is that logging during patching can no longer be directed to the main log (it'll get mixed up with other messages). Now directed to <ksp_root>/Logs/ModuleManager.log
1 parent ea7b05a commit d50fc9e

10 files changed

Lines changed: 268 additions & 164 deletions

File tree

‎ModuleManager/MMPatchLoader.cs‎

Lines changed: 25 additions & 124 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,4 @@
11
using System;
2-
using System.Collections;
32
using System.Collections.Generic;
43
using System.Diagnostics;
54
using System.Diagnostics.CodeAnalysis;
@@ -14,9 +13,7 @@
1413

1514
using ModuleManager.Logging;
1615
using ModuleManager.Extensions;
17-
using ModuleManager.Collections;
1816
using ModuleManager.Tags;
19-
using ModuleManager.Threading;
2017
using ModuleManager.Patches;
2118
using ModuleManager.Progress;
2219
using NodeStack = ModuleManager.Collections.ImmutableStack<ConfigNode>;
@@ -27,16 +24,14 @@ namespace ModuleManager
2724
{
2825
[SuppressMessage("ReSharper", "StringLastIndexOfIsCultureSpecific.1")]
2926
[SuppressMessage("ReSharper", "StringIndexOfIsCultureSpecific.1")]
30-
public class MMPatchLoader : LoadingSystem
27+
public class MMPatchLoader
3128
{
3229
public string status = "";
3330

3431
public string errors = "";
3532

3633
public static bool keepPartDB = false;
3734

38-
private string activity = "Module Manager";
39-
4035
private static readonly Dictionary<string, Regex> regexCache = new Dictionary<string, Regex>();
4136

4237
private UrlDir.UrlFile physicsUrlFile;
@@ -48,59 +43,23 @@ public class MMPatchLoader : LoadingSystem
4843

4944
private IBasicLogger logger;
5045

51-
private float progressFraction = 0;
52-
53-
public static MMPatchLoader Instance { get; private set; }
54-
55-
private void Awake()
56-
{
57-
if (Instance != null)
58-
{
59-
DestroyImmediate(this);
60-
return;
61-
}
62-
Instance = this;
63-
64-
logger = new ModLogger("ModuleManager", new UnityLogger(Debug.unityLogger));
65-
}
66-
67-
private bool ready;
68-
69-
public override bool IsReady()
70-
{
71-
return ready;
72-
}
73-
74-
public override float ProgressFraction() => progressFraction;
75-
76-
public override string ProgressTitle()
77-
{
78-
return activity;
79-
}
80-
81-
public override void StartLoad()
46+
public static void AddPostPatchCallback(ModuleManagerPostPatchCallback callback)
8247
{
83-
ready = false;
84-
85-
// DB check used to track the now fixed TextureReplacer corruption
86-
//checkValues();
87-
88-
StartCoroutine(ProcessPatch());
48+
PostPatchLoader.AddPostPatchCallback(callback);
8949
}
9050

91-
public static void AddPostPatchCallback(ModuleManagerPostPatchCallback callback)
51+
public MMPatchLoader(IBasicLogger logger)
9252
{
93-
PostPatchLoader.AddPostPatchCallback(callback);
53+
this.logger = logger ?? throw new ArgumentNullException(nameof(logger));
9454
}
9555

96-
private IEnumerator ProcessPatch()
56+
public IEnumerable<IProtoUrlConfig> Run()
9757
{
9858
Stopwatch patchSw = new Stopwatch();
9959
patchSw.Start();
10060

10161
status = "Checking Cache";
10262
logger.Info(status);
103-
yield return null;
10463

10564
bool useCache = false;
10665
try
@@ -115,7 +74,6 @@ private IEnumerator ProcessPatch()
11574
#if DEBUG
11675
//useCache = false;
11776
#endif
118-
yield return null;
11977

12078
IEnumerable<IProtoUrlConfig> databaseConfigs = null;
12179

@@ -126,8 +84,6 @@ private IEnumerator ProcessPatch()
12684
logger.Info(status);
12785
IEnumerable<string> mods = ModListGenerator.GenerateModList(progress, logger);
12886

129-
yield return null;
130-
13187
// If we don't use the cache then it is best to clean the PartDatabase.cfg
13288
if (!keepPartDB && File.Exists(partDatabasePath))
13389
File.Delete(partDatabasePath);
@@ -139,8 +95,6 @@ private IEnumerator ProcessPatch()
13995
status = "Extracting patches";
14096
logger.Info(status);
14197

142-
yield return null;
143-
14498
UrlDir gameData = GameDatabase.Instance.root.children.First(dir => dir.type == UrlDir.DirectoryType.GameData && dir.name == "");
14599
INeedsChecker needsChecker = new NeedsChecker(mods, gameData, progress, logger);
146100
ITagListParser tagListParser = new TagListParser(progress);
@@ -160,73 +114,30 @@ private IEnumerator ProcessPatch()
160114
status = "Applying patches";
161115
logger.Info(status);
162116

163-
yield return null;
164-
165-
MessageQueue<ILogMessage> logQueue = new MessageQueue<ILogMessage>();
166-
IBasicLogger patchLogger = new QueueLogger(logQueue);
167-
IPatchProgress threadPatchProgress = new PatchProgress(progress, patchLogger);
168-
PatchApplier applier = new PatchApplier(threadPatchProgress, patchLogger);
117+
IPass currentPass = null;
118+
float nextUpdate = Time.realtimeSinceStartup + yieldInterval;
169119

170-
logger.Info("Starting patch thread");
171-
172-
ITaskStatus patchThread = BackgroundTask.Start(delegate
120+
progress.OnPassStarted.Add(delegate (IPass pass)
173121
{
174-
databaseConfigs = applier.ApplyPatches(patchList);
122+
currentPass = pass;
123+
StatusUpdate(progress, currentPass.Name);
175124
});
176125

177-
float nextYield = Time.realtimeSinceStartup + yieldInterval;
178-
179-
float updateTimeRemaining()
180-
{
181-
float timeRemaining = nextYield - Time.realtimeSinceStartup;
182-
if (timeRemaining < 0)
183-
{
184-
nextYield = Time.realtimeSinceStartup + yieldInterval;
185-
StatusUpdate(progress);
186-
activity = applier.Activity;
187-
}
188-
return timeRemaining;
189-
}
190-
191-
while (patchThread.IsRunning)
126+
progress.OnPatchApplied.Add(delegate
192127
{
193-
foreach (ILogMessage message in logQueue.TakeAll())
128+
if (Time.realtimeSinceStartup > nextUpdate)
194129
{
195-
message.LogTo(logger);
196-
197-
if (updateTimeRemaining() < 0) yield return null;
130+
StatusUpdate(progress, currentPass.Name);
131+
nextUpdate = Time.realtimeSinceStartup + yieldInterval;
198132
}
133+
});
199134

200-
float timeRemaining = updateTimeRemaining();
201-
if (timeRemaining > 0) System.Threading.Thread.Sleep((int)(timeRemaining * 1000));
202-
yield return null;
203-
}
135+
PatchApplier applier = new PatchApplier(progress, logger);
136+
databaseConfigs = applier.ApplyPatches(patchList);
204137

205138
StatusUpdate(progress);
206-
activity = "ModuleManager - finishing up";
207-
yield return null;
208-
209-
// Clear any log messages that might still be in the queue
210-
foreach (ILogMessage message in logQueue.TakeAll())
211-
{
212-
message.LogTo(logger);
213-
}
214-
215-
if (patchThread.IsExitedWithError)
216-
{
217-
progress.Exception("The patch runner threw an exception", patchThread.Exception);
218-
FatalErrorHandler.HandleFatalError("The patch runner threw an exception");
219-
yield break;
220-
}
221-
if (databaseConfigs == null)
222-
{
223-
progress.Error("The patcher returned a null collection of configs");
224-
FatalErrorHandler.HandleFatalError("The patcher returned a null collection of configs");
225-
yield break;
226-
}
227139

228140
logger.Info("Done patching");
229-
yield return null;
230141

231142
PurgeUnused();
232143

@@ -264,7 +175,6 @@ float updateTimeRemaining()
264175
{
265176
status = "Saving Cache";
266177
logger.Info(status);
267-
yield return null;
268178
CreateCache(databaseConfigs, progress.Counter.patchedNodes);
269179
}
270180

@@ -279,26 +189,15 @@ float updateTimeRemaining()
279189
{
280190
status = "Loading from Cache";
281191
logger.Info(status);
282-
yield return null;
283192
databaseConfigs = LoadCache();
284193
}
285194

286-
foreach (UrlDir.UrlFile file in GameDatabase.Instance.root.AllConfigFiles)
287-
{
288-
file.configs.Clear();
289-
}
290-
291-
foreach (IProtoUrlConfig protoConfig in databaseConfigs)
292-
{
293-
protoConfig.UrlFile.AddConfig(protoConfig.Node);
294-
}
295-
296195
logger.Info(status + "\n" + errors);
297196

298197
patchSw.Stop();
299198
logger.Info("Ran in " + ((float)patchSw.ElapsedMilliseconds / 1000).ToString("F3") + "s");
300199

301-
ready = true;
200+
return databaseConfigs;
302201
}
303202

304203
private void LoadPhysicsConfig()
@@ -583,17 +482,19 @@ private IEnumerable<IProtoUrlConfig> LoadCache()
583482
logger.Warning("Parent null for " + parentUrl);
584483
}
585484
}
586-
progressFraction = 1;
587485
logger.Info("Cache Loaded");
588486

589487
return databaseConfigs;
590488
}
591489

592-
private void StatusUpdate(IPatchProgress progress)
490+
private void StatusUpdate(IPatchProgress progress, string activity = null)
593491
{
594-
progressFraction = progress.ProgressFraction;
595-
596492
status = "ModuleManager: " + progress.Counter.patchedNodes + " patch" + (progress.Counter.patchedNodes != 1 ? "es" : "") + " applied";
493+
if (progress.ProgressFraction < 1f - float.Epsilon)
494+
status += " (" + progress.ProgressFraction * 100 + "%)";
495+
496+
if (activity != null)
497+
status += "\n" + activity;
597498

598499
if (progress.Counter.warnings > 0)
599500
status += ", found <color=yellow>" + progress.Counter.warnings + " warning" + (progress.Counter.warnings != 1 ? "s" : "") + "</color>";

‎ModuleManager/MMPatchRunner.cs‎

Lines changed: 125 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,125 @@
1+
using System;
2+
using System.Collections;
3+
using System.Collections.Generic;
4+
using System.IO;
5+
using UnityEngine;
6+
using ModuleManager.Collections;
7+
using ModuleManager.Extensions;
8+
using ModuleManager.Logging;
9+
using ModuleManager.Threading;
10+
11+
namespace ModuleManager
12+
{
13+
public class MMPatchRunner
14+
{
15+
private const float TIME_TO_WAIT_FOR_LOGS = 0.05f;
16+
17+
private readonly IBasicLogger kspLogger;
18+
19+
public string Status { get; private set; } = "";
20+
public string Errors { get; private set; } = "";
21+
22+
public MMPatchRunner(IBasicLogger kspLogger)
23+
{
24+
this.kspLogger = kspLogger ?? throw new ArgumentNullException(nameof(kspLogger));
25+
}
26+
27+
public IEnumerator Run()
28+
{
29+
PostPatchLoader.Instance.databaseConfigs = null;
30+
31+
string logsDirPath = Path.Combine(KSPUtil.ApplicationRootPath, "Logs");
32+
if (!Directory.Exists(logsDirPath)) Directory.CreateDirectory(logsDirPath);
33+
string logPath = Path.Combine(logsDirPath, "ModuleManager.log");
34+
35+
kspLogger.Info("Patching started on a new thread, all output will be directed to " + logPath);
36+
37+
MessageQueue<ILogMessage> kspLogQueue = new MessageQueue<ILogMessage>();
38+
MessageQueue<ILogMessage> mmLogQueue = new MessageQueue<ILogMessage>();
39+
bool logThreadExitFlag = false;
40+
ITaskStatus loggingThreadStatus = BackgroundTask.Start(delegate
41+
{
42+
QueueLogger kspLogger = new QueueLogger(kspLogQueue);
43+
using (StreamLogger streamLogger = new StreamLogger(new FileStream(logPath, FileMode.Create), kspLogger))
44+
{
45+
while (!logThreadExitFlag)
46+
{
47+
float waitTargetTime = Time.realtimeSinceStartup + TIME_TO_WAIT_FOR_LOGS;
48+
49+
foreach (ILogMessage message in mmLogQueue.TakeAll())
50+
{
51+
message.LogTo(streamLogger);
52+
}
53+
54+
float timeRemaining = waitTargetTime - Time.realtimeSinceStartup;
55+
if (timeRemaining > 0)
56+
System.Threading.Thread.Sleep((int)(timeRemaining * 1000));
57+
}
58+
59+
foreach (ILogMessage message in mmLogQueue.TakeAll())
60+
{
61+
message.LogTo(streamLogger);
62+
}
63+
64+
streamLogger.Info("Done!");
65+
}
66+
});
67+
68+
// Wait for game database to be initialized for the 2nd time
69+
yield return null;
70+
71+
IEnumerable<IProtoUrlConfig> databaseConfigs = null;
72+
73+
MMPatchLoader patchLoader = new MMPatchLoader(new QueueLogger(mmLogQueue));
74+
75+
ITaskStatus patchingThreadStatus = BackgroundTask.Start(delegate
76+
{
77+
databaseConfigs = patchLoader.Run();
78+
});
79+
80+
while(true)
81+
{
82+
yield return null;
83+
84+
if (!patchingThreadStatus.IsRunning)
85+
logThreadExitFlag = true;
86+
87+
Status = patchLoader.status;
88+
Errors = patchLoader.errors;
89+
90+
foreach (ILogMessage message in kspLogQueue.TakeAll())
91+
{
92+
message.LogTo(kspLogger);
93+
}
94+
95+
if (!patchingThreadStatus.IsRunning && !loggingThreadStatus.IsRunning) break;
96+
}
97+
98+
foreach (ILogMessage message in kspLogQueue.TakeAll())
99+
{
100+
message.LogTo(kspLogger);
101+
}
102+
103+
if (patchingThreadStatus.IsExitedWithError)
104+
{
105+
kspLogger.Exception("The patching thread threw an exception", patchingThreadStatus.Exception);
106+
FatalErrorHandler.HandleFatalError("The patching thread threw an exception");
107+
}
108+
109+
if (loggingThreadStatus.IsExitedWithError)
110+
{
111+
kspLogger.Exception("The logging thread threw an exception", loggingThreadStatus.Exception);
112+
FatalErrorHandler.HandleFatalError("The logging thread threw an exception");
113+
}
114+
115+
if (databaseConfigs == null)
116+
{
117+
kspLogger.Error("The patcher returned a null collection of configs");
118+
FatalErrorHandler.HandleFatalError("The patcher returned a null collection of configs");
119+
yield break;
120+
}
121+
122+
PostPatchLoader.Instance.databaseConfigs = databaseConfigs;
123+
}
124+
}
125+
}

0 commit comments

Comments
 (0)