diff --git a/Models/PaintRecipe.cs b/Models/PaintRecipe.cs --- a/Models/PaintRecipe.cs +++ b/Models/PaintRecipe.cs @@ -272,6 +272,27 @@ namespace DesertPaintCodex.Models } } + public uint Concentration + { + get + { + uint concentration = 0; + foreach (ReagentQuantity ingredient in _recipe) + { + string reagentName = ingredient.Name; + if (string.IsNullOrEmpty(reagentName)) + { + continue; + } + + Reagent reagent = ReagentService.GetReagent(reagentName); + if (reagent.IsCatalyst) continue; + concentration += ingredient.Quantity; + } + return concentration; + } + } + public uint GetBulkCost(uint quantity) { uint cost = 0; diff --git a/Models/RecipeSearchNode.cs b/Models/RecipeSearchNode.cs --- a/Models/RecipeSearchNode.cs +++ b/Models/RecipeSearchNode.cs @@ -27,6 +27,10 @@ namespace DesertPaintCodex.Models public uint FullQuantity { get; set; } public uint MinReagents { get; set; } + public bool ShouldLog { get; private set; } + + public Action? WriteLog = null; + private uint _maxReagents; public uint MaxReagents { @@ -71,6 +75,8 @@ namespace DesertPaintCodex.Models { CurrentWeights[i] = other.CurrentWeights[i]; } + + RefreshShouldLog(); } public RecipeSearchNode(List costSortedReagents, uint[] reagents) @@ -108,6 +114,8 @@ namespace DesertPaintCodex.Models MaxReagents = (uint) _nextReagentPos; CurrentWeights = new uint[MaxReagents]; UsedQuantity = 0; + + RefreshShouldLog(); } // top-level search @@ -132,6 +140,8 @@ namespace DesertPaintCodex.Models MaxReagents = 1; CurrentWeights = new uint[MaxReagents]; UsedQuantity = 0; + + RefreshShouldLog(); } public RecipeSearchNode(List costSortedReagents) @@ -154,6 +164,14 @@ namespace DesertPaintCodex.Models MaxReagents = 1; CurrentWeights = new uint[MaxReagents]; UsedQuantity = 0; + + RefreshShouldLog(); + } + + private void RefreshShouldLog() + { + ShouldLog = false; + // (ReagentCount == 5) && (GetReagent(0).Name == "Iron") && (GetReagent(1).Name == "Red Sand") && (GetReagent(2).Name == "Sulfur") && (GetReagent(3).Name == "Carrot") && (GetReagent(4).Name == "Copper"); } public Reagent GetReagent(int idx) @@ -171,6 +189,7 @@ namespace DesertPaintCodex.Models } _reagents[_nextReagentPos - 1] = _invalidReagent; --_nextReagentPos; + RefreshShouldLog(); } public void ReplaceLastReagent(uint reagentIdx) @@ -186,6 +205,7 @@ namespace DesertPaintCodex.Models { ++CatalystCount; } + RefreshShouldLog(); } public uint NextFreeReagent(uint startIdx) @@ -235,7 +255,11 @@ namespace DesertPaintCodex.Models return; } UsedQuantity = 0; - uint remainingReagents = ((uint)_nextReagentPos - CatalystCount); + if (ShouldLog) + { + WriteLog?.Invoke($" == initializing {this} @ quantity {CurrentTargetQuantity} with {CatalystCount} catalysts =="); + } + uint remainingReagents = ((uint)_nextReagentPos); // Remaining reagents, including catalysts uint remainingWeight = CurrentTargetQuantity - CatalystCount; for (int i = 0; i < _nextReagentPos; ++i) { @@ -246,6 +270,11 @@ namespace DesertPaintCodex.Models //Console.WriteLine("Init catalyst {0} weight 1", reagent.Name); CurrentWeights[i] = 1; ++UsedQuantity; + // This takes quantity but not weight (concentration) + if (ShouldLog) + { + WriteLog?.Invoke($" + 1 {reagent.Name} (catalyst)"); + } } else { @@ -256,12 +285,17 @@ namespace DesertPaintCodex.Models } uint weight = Math.Min(remainingWeight - (remainingReagents-1), reagentMaxWeight); //Console.WriteLine("Init reagent {0} weight {1}", reagent.Name, weight); + if (ShouldLog) + { + WriteLog?.Invoke($" + {weight} {reagent.Name} (remain: weight={remainingWeight} reagents={remainingReagents})"); + } remainingWeight -= weight; CurrentWeights[i] = weight; UsedQuantity += weight; } --remainingReagents; } + RefreshShouldLog(); } public void SetWeight(int idx, uint quantity) @@ -432,7 +466,24 @@ namespace DesertPaintCodex.Models break; } } + RefreshShouldLog(); return success; - } + } + + public override string ToString() + { + if (_nextReagentPos == 0) + { + return "No ingredients"; + } + System.Text.StringBuilder sb = new System.Text.StringBuilder(); + sb.Append(_costSortedReagents[(int)_reagents[0]].Name); + for (int idx = 1; idx < _nextReagentPos; ++idx) + { + Reagent reagent = _costSortedReagents[(int)_reagents[idx]]; + sb.Append($", {reagent.Name}"); + } + return sb.ToString(); + } } } \ No newline at end of file diff --git a/Models/Settings.cs b/Models/Settings.cs --- a/Models/Settings.cs +++ b/Models/Settings.cs @@ -17,8 +17,9 @@ namespace DesertPaintCodex.Models public bool TryGet(string key, out bool value) { value = false; - return _settings.TryGetValue(key.ToLower(), out string? valStr) - && bool.TryParse(valStr, out value); + bool found = _settings.TryGetValue(key.ToLower(), out string? valStr); + found = found && bool.TryParse(valStr, out value); + return found; } public void Set(string key, int value) diff --git a/Services/RecipeGenerator.cs b/Services/RecipeGenerator.cs --- a/Services/RecipeGenerator.cs +++ b/Services/RecipeGenerator.cs @@ -93,6 +93,35 @@ namespace DesertPaintCodex.Services set => _log = value != null ? new StreamWriter(value) : null; } + public void FlushLog() + { + _log?.Flush(); + } + + public void CloseLog() + { + _log?.Close(); + _log = null; + } + + private void WriteLog(string msg) + { + if (_log == null) return; + lock (_workerLock) + { + _log.WriteLine(msg); + } + } + + private void WriteLog(string msg, params object[] args) + { + if (_log == null) return; + lock(_workerLock) + { + _log.WriteLine(msg, args); + } + } + private class ReagentCostSort : IComparer { public int Compare(Reagent? reagent1, Reagent? reagent2) @@ -165,6 +194,8 @@ namespace DesertPaintCodex.Services // Pre-populate recipes list with: // 1) 1-ingredient recipes @ min concentration for all enabled ingredients with a count >= min concentration // 2) any previously-generated recipes + WriteLog($"===================== BEGIN RECIPE GENERATION ========================== {DateTime.Now}"); + WriteLog("Pre-populating basic recipes."); int enabledReagentCount = 0; PaintRecipe recipe = new(); foreach (var reagent in _costSortedReagents.Where(reagent => reagent.Enabled)) @@ -196,6 +227,7 @@ namespace DesertPaintCodex.Services MinReagents = minReagents, MaxReagents = maxReagents }; + initialNode.WriteLog = WriteLog; if (MinReagents > 1) { @@ -205,6 +237,7 @@ namespace DesertPaintCodex.Services //Console.WriteLine("Initial node at size {0}/{1} with recipe: {2}", initialNode.ReagentCount, minReagents, initialNode.TestRecipe.ToString()); RecipeSearchNode searchNode = new RecipeSearchNode(initialNode); + searchNode.WriteLog = WriteLog; _searchQueue.Enqueue(searchNode); } } @@ -216,7 +249,7 @@ namespace DesertPaintCodex.Services _recipeCount = 0; - _log?.WriteLine("Begin recipe generation: MaxConcentration={0} MinReagents={1} MaxReagents={2} FullQuantity={3} FullQuantityDepth={4}", MaxConcentration, MinReagents, MaxReagents, FullQuantity, FullQuantityDepth); + WriteLog("Begin recipe generation: MaxConcentration={0} MinReagents={1} MaxReagents={2} FullQuantity={3} FullQuantityDepth={4}", MaxConcentration, MinReagents, MaxReagents, FullQuantity, FullQuantityDepth); // start worker threads to do the actual work ResumeRecipeGeneration(); @@ -232,7 +265,7 @@ namespace DesertPaintCodex.Services _running = true; _requestCancel = false; - _log?.WriteLine("Resuming recipe generation: pre-threads={0} reagent count={1} search queue={2}", _runningThreads, _costSortedReagents.Count, _searchQueue.Count); + WriteLog("Resuming recipe generation: pre-threads={0} reagent count={1} search queue={2}", _runningThreads, _costSortedReagents.Count, _searchQueue.Count); _runningThreads = 0; // presumably! int threadCount = Math.Min(Math.Min(_costSortedReagents.Count, _searchQueue.Count), (int)MaxThreads); @@ -242,6 +275,7 @@ namespace DesertPaintCodex.Services } _generatorThreads.Clear(); Console.WriteLine("Starting {0} generator threads.", threadCount); + WriteLog($"===== Starting {threadCount} threads."); for (int i = 0; i < threadCount; ++i) { Thread thr = new(Generate) {Priority = ThreadPriority.BelowNormal}; @@ -381,6 +415,7 @@ namespace DesertPaintCodex.Services MaxReagents = MaxReagents, MaxConcentration = MaxConcentration }; + node.WriteLog = WriteLog; success = success && node.LoadState(reader); if (success) { @@ -420,10 +455,12 @@ namespace DesertPaintCodex.Services { ok = _searchQueue.TryDequeue(out node); } - - if (!ok) continue; + + if (!ok) break; Debug.Assert(node != null); + + node.WriteLog = WriteLog; if (Mode == SearchType.DepthFirst) { @@ -432,6 +469,10 @@ namespace DesertPaintCodex.Services : node.MaxConcentration + 1; do { --targetQuantity; + if (node.ShouldLog) + { + WriteLog($" == Initializing {node} for quantity {targetQuantity}"); + } node.InitForQuantity(targetQuantity); } while (targetQuantity > MinConcentration && (node.CurrentTargetQuantity != node.UsedQuantity)); @@ -449,6 +490,10 @@ namespace DesertPaintCodex.Services : node.MaxConcentration; do { ++targetQuantity; + if (node.ShouldLog) + { + WriteLog($" == Initializing {node} for quantity {targetQuantity}"); + } node.InitForQuantity(targetQuantity); } while ((targetQuantity < quantityLimit) && (node.CurrentTargetQuantity != node.UsedQuantity)); @@ -462,7 +507,7 @@ namespace DesertPaintCodex.Services // stopped because cancel was requested - requeue the node in its current state for resume _searchQueue.Enqueue(node); } - } while (!_requestCancel && ok); + } while (!_requestCancel); bool done; lock(_workerLock) @@ -489,28 +534,43 @@ namespace DesertPaintCodex.Services string colorName = PaletteService.FindNearest(recipe.ReactedColor); lock (_workerLock) { + uint newCost = recipe.Cost; if (_recipeCosts.TryGetValue(colorName, out var cost)) { - if (cost <= recipe.Cost) return; + if (cost < newCost) + { + // WriteLog($"Skipping recipe (cost {newCost} > {cost}): {recipe}"); + return; + } + PaintRecipe origRecipe = _recipes[colorName]; + if (cost == newCost && recipe.Concentration >= origRecipe.Concentration) + { + // Same cost, greater concentration - use the lower concentration recipe + WriteLog($"Skipping recipe (cost {newCost}, {recipe.Concentration} >= {origRecipe.Concentration}): {recipe}"); + return; + } - _recipes[colorName].CopyFrom(recipe); - _recipeCosts[colorName] = recipe.Cost; - _log?.WriteLine("New recipe (cost {0}): {1}", recipe.Cost, recipe); + _recipes[colorName].CopyFrom(recipe); // Copy recipe because the one passed in should be const and will get overwritten + _recipeCosts[colorName] = newCost; + WriteLog($"Replacing recipe (cost {newCost} < {cost}): {recipe}"); if (NewRecipe == null) return; - NewRecipeEventArgs args = new(colorName, recipe); + NewRecipeEventArgs args = new(colorName, _recipes[colorName]); NewRecipe(this, args); } else { // This would be an error! - _recipeCosts.Add(colorName, recipe.Cost); - _recipes.Add(colorName, new PaintRecipe(recipe)); - + _recipeCosts.Add(colorName, newCost); + PaintRecipe newRecipe = new PaintRecipe(recipe); // Copy recipe because the one passed in should be const and will get overwritten + _recipes.Add(colorName, newRecipe); + + WriteLog($"New recipe (cost {newCost}): {recipe}"); + if (NewRecipe == null) return; - NewRecipeEventArgs args = new(colorName, recipe); + NewRecipeEventArgs args = new(colorName, newRecipe); NewRecipe(this, args); } } @@ -601,6 +661,8 @@ namespace DesertPaintCodex.Services return true; } + string origNodeVal = node.ToString(); + // Try next quantity uint newQuantity; uint quantityLimit = ((uint)node.ReagentCount <= FullQuantityDepth) ? ((uint)node.ReagentCount * FullQuantity) : node.MaxConcentration; @@ -608,16 +670,35 @@ namespace DesertPaintCodex.Services newQuantity = node.CurrentTargetQuantity + 1; //Console.WriteLine("Try quantity {0}", newQuantity); if (newQuantity > quantityLimit) continue; - + + if (node.ShouldLog) + { + WriteLog($" == Initializing {node} for quantity {newQuantity}"); + } node.InitForQuantity(newQuantity); if (node.CurrentTargetQuantity <= node.UsedQuantity) { //if (log != null) { lock(log) { log.WriteLine("Update quantity to {0}", node.CurrentTargetQuantity); } } + if (node.ShouldLog) + { + WriteLog($" == {node} quantity {newQuantity}"); + } return true; } } while (newQuantity < quantityLimit); bool ok = NextReagentSetBreadthFirst(node, node.MinReagents, node.MaxReagents); + if (node.ShouldLog) + { + if (ok) + { + WriteLog($"==== {origNodeVal} next reagent set: {node} @ {node.CurrentTargetQuantity}"); + } + else + { + WriteLog($"==== done with reagent set: {origNodeVal}"); + } + } return ok; } @@ -629,6 +710,10 @@ namespace DesertPaintCodex.Services // next reagent in last position // if at end, pop reagent //Console.WriteLine("Finding new recipe after quantity {0}/{1} used {2}", newQuantity, node.MaxConcentration, node.UsedQuantity); + if (node.ShouldLog) + { + WriteLog($" == Initializing {node} for quantity {node.MinConcentration + node.CatalystCount}"); + } node.InitForQuantity(node.MinConcentration + node.CatalystCount); // reset quantity int currentDepth = node.ReagentCount; bool recipeFound; @@ -691,6 +776,7 @@ namespace DesertPaintCodex.Services } //Console.WriteLine("Catalysts: {0} Reagents: {1} Min: {2}", node.CatalystCount, node.ReagentCount, node.MinReagents); } while ((node.CatalystCount >= node.ReagentCount) && (node.ReagentCount >= minReagents)); // make sure to skip all-catalyst combinations + if (recipeFound) { break; @@ -702,7 +788,14 @@ namespace DesertPaintCodex.Services } } while (currentDepth <= maxReagents); - if (!recipeFound) return false; + if (!recipeFound) + { + if (node.ShouldLog) + { + WriteLog($" == no more recipes for {node}"); + } + return false; + } node.InitForQuantity(node.MinConcentration+node.CatalystCount); // minimum quantity for this recipe @@ -725,6 +818,10 @@ namespace DesertPaintCodex.Services { node.TestRecipe.AddReagent(node.GetReagent(i).Name, node.CurrentWeights[i]); } + if (node.ShouldLog) + { + WriteLog($" -> {node.TestRecipe}"); + } AddCheapestRecipe(node.TestRecipe); //if (log != null) { lock(log) { log.WriteLine("Tested recipe: {0}", node.TestRecipe); } } } @@ -737,6 +834,10 @@ namespace DesertPaintCodex.Services { // not possible to make a valid recipe //Console.WriteLine("Insufficient remaining weight"); + if (node.ShouldLog) + { + WriteLog($" ***** Not enough remaining weight in recipe {node} at target quantity {node.CurrentTargetQuantity} catalysts {node.CatalystCount} min concentration {MinConcentration}"); + } return false; } //uint remainingReagents = (uint)node.Reagents.Count - node.CatalystCount; @@ -745,6 +846,7 @@ namespace DesertPaintCodex.Services uint weightToConsume = 0; uint spaceBelow = 0; int reagentsBelow = 0; + // Start from the end of the current reagent list and work to the front for (int i = (int)depth-1 ; i >= 0; --i) { uint currentWeight = node.CurrentWeights[i]; @@ -822,6 +924,16 @@ namespace DesertPaintCodex.Services _requestCancel = true; } + public void ResetQueue() + { + lock (_workerLock) + { + // Don't reset the queue ever while running + if (_running) return; + _searchQueue.Clear(); + } + } + public void Reset() { foreach (PaintRecipe recipe in _recipes.Values) diff --git a/ViewModels/RecipeGeneratorViewModel.cs b/ViewModels/RecipeGeneratorViewModel.cs --- a/ViewModels/RecipeGeneratorViewModel.cs +++ b/ViewModels/RecipeGeneratorViewModel.cs @@ -126,8 +126,8 @@ namespace DesertPaintCodex.ViewModels SettingsService.Get("Generator.Logging", out bool logGenerator, false); if (logGenerator) { - string logDir = Environment.GetFolderPath(Environment.SpecialFolder.MyDocuments); - _generator.Log = System.IO.Path.Combine(logDir, "dpl_generator.txt"); + string logDir = DesertPaintCodex.Util.FileUtils.AppDataPath; + _generator.Log = System.IO.Path.Combine(logDir, "recipe_generator_log.txt"); } if (ribbonMode) @@ -153,7 +153,15 @@ namespace DesertPaintCodex.ViewModels SaveSettings(_ribbonMode ? "Ribbon" : "Paint"); _updateTimer.Start(); SelectedView = 1; - + + _generator.CloseLog(); + SettingsService.Get("Generator.Logging", out bool logGenerator, false); + if (logGenerator) + { + string logDir = DesertPaintCodex.Util.FileUtils.AppDataPath; + _generator.Log = System.IO.Path.Combine(logDir, "recipe_generator_log.txt"); + } + _generator.BeginRecipeGeneration( _minConcentration, (uint)MaxConcentration, @@ -171,7 +179,9 @@ namespace DesertPaintCodex.ViewModels IsInProgress = false; _updateTimer.Stop(); _profile.SaveRecipes(); - + _generator.ResetQueue(); + SaveState(); + CanClear = true; } @@ -189,7 +199,15 @@ namespace DesertPaintCodex.ViewModels IsRunning = true; _updateTimer.Start(); SelectedView = 1; - + + _generator.CloseLog(); + SettingsService.Get("Generator.Logging", out bool logGenerator, false); + if (logGenerator) + { + string logDir = DesertPaintCodex.Util.FileUtils.AppDataPath; + _generator.Log = System.IO.Path.Combine(logDir, "recipe_generator_log.txt"); + } + _generator.ResumeRecipeGeneration(); } @@ -302,19 +320,27 @@ namespace DesertPaintCodex.ViewModels private void OnGeneratorStopped(object? sender, EventArgs args) { - SaveState(); - if (_saving) { + SaveState(); + _generator.ResumeRecipeGeneration(); _lastSave = DateTime.Now; _saving = false; return; } - if (IsPaused) return; + _generator.FlushLog(); + + if (IsPaused) + { + SaveState(); + _generator.CloseLog(); + return; + } End(); + _generator.CloseLog(); } private void Update(object? sender, EventArgs e)