improved logging facilities, improved game traversal efficiency

Ficdown.Console/Program.cs

@@ -84,6 +84,9 @@ private static int Main(string[] args)
                 return 0;
             }
 
+            Logger.Initialize(debug);
+            var logger = Logger.GetLogger<Program>();
+
             var lintMode = format == "lint";
 
             if(!lintMode)
@@ -95,7 +98,7 @@ private static int Main(string[] args)
                 }
                 if (!File.Exists(infile))
                 {
-                    Console.WriteLine(@"Source file {0} not found.", infile);
+                    logger.Error($"Source file {infile} not found.");
                     return 2;
                 }
                 if (string.IsNullOrWhiteSpace(output))
@@ -108,28 +111,28 @@ private static int Main(string[] args)
 
                 if (!string.IsNullOrWhiteSpace(output) && (Directory.Exists(output) || File.Exists(output)))
                 {
-                    Console.WriteLine(@"Specified output {0} already exists.", output);
+                    logger.Error($"Specified output {output} already exists.");
                     return 2;
                 }
                 if (!string.IsNullOrWhiteSpace(tempdir))
                 {
                     if (!Directory.Exists(tempdir))
                     {
-                        Console.WriteLine(@"Template directory {0} does not exist.", tempdir);
+                        logger.Error($"Template directory {tempdir} does not exist.");
                         return 2;
                     }
                     if (!File.Exists(Path.Combine(tempdir, "index.html")) ||
                         !File.Exists(Path.Combine(tempdir, "scene.html")) ||
                         !File.Exists(Path.Combine(tempdir, "styles.css")))
                     {
-                        Console.WriteLine(
+                        logger.Error(
                             @"Template directory must contain ""index.html"", ""scene.html"", and ""style.css"" files.");
                     }
                 }
 
                 if (!string.IsNullOrWhiteSpace(images) && !Directory.Exists(images))
                 {
-                    Console.WriteLine(@"Images directory {0} does not exist.", images);
+                    logger.Error($"Images directory {images} does not exist.");
                     return 2;
                 }
             }
@@ -140,7 +143,7 @@ private static int Main(string[] args)
             if(!lintMode)
             {
                 storyText = File.ReadAllText(infile);
-                Console.WriteLine(@"Parsing story...");
+                logger.Log(@"Parsing story...");
             }
             else
             {
@@ -149,8 +152,8 @@ private static int Main(string[] args)
 
             var story = parser.ParseStory(storyText);
 
-            parser.Warnings.Select(w => w.ToString()).Distinct().ToList().ForEach(s => Console.WriteLine(s));
-            story.Orphans.ToList().ForEach(o => Console.WriteLine("Warning L{0},1: \"{1}\": Unreachable {2}", o.LineNumber, o.Name, o.Type));
+            parser.Warnings.Select(w => w.ToString()).Distinct().ToList().ForEach(s => logger.Raw(s));
+            story.Orphans.ToList().ForEach(o => logger.Raw($"Warning L{o.LineNumber},1: \"{o.Name}\": Unreachable {o.Type}"));
 
             if(!lintMode && parser.Warnings.Count() == 0)
             {
@@ -164,7 +167,7 @@ private static int Main(string[] args)
                     case "epub":
                         if (string.IsNullOrWhiteSpace(author))
                         {
-                            Console.WriteLine(@"Epub format requires the --author argument.");
+                            logger.Error(@"Epub format requires the --author argument.");
                             return 1;
                         }
                         rend = new EpubRenderer(author, bookid, language);
@@ -183,11 +186,11 @@ private static int Main(string[] args)
 
                 if (!string.IsNullOrWhiteSpace(images)) rend.ImageDir = images;
 
-                Console.WriteLine(@"Rendering story...");
+                logger.Log(@"Rendering story...");
 
                 rend.Render(story, output, debug);
 
-                Console.WriteLine(@"Done.");
+                logger.Log(@"Done.");
             }
             return 0;
         }

Ficdown.Parser.Tests/IntegrationTests.cs

@@ -9,6 +9,7 @@ public class IntegrationTests
         [Fact]
         public void CanParseValidStoryFile()
         {
+            Logger.Initialize(true);
             var parser = new FicdownParser();
             var storyText = File.ReadAllText(Path.Combine(Template.BaseDir, "TestStories", "CloakOfDarkness.md"));
             var story = parser.ParseStory(storyText);

Ficdown.Parser/FicDownParser.cs

@@ -12,6 +12,7 @@ namespace Ficdown.Parser
 
     public class FicdownParser
     {
+        private static Logger _logger = Logger.GetLogger<FicdownParser>();
         public List<FicdownException> Warnings { get; private set; }
 
         private IBlockHandler _blockHandler;
@@ -64,8 +65,11 @@ public FicdownParser()
         public ResolvedStory ParseStory(string storyText)
         {
             var lines = storyText.Split(new[] {"\n", "\r\n"}, StringSplitOptions.None);
+            _logger.Debug($"Parsed {lines.Length} lines.");
             var blocks = BlockHandler.ExtractBlocks(lines);
+            _logger.Debug($"Extracted {blocks.Count()} blocks.");
             var story = BlockHandler.ParseBlocks(blocks);
+            _logger.Debug("Finished initial story breakdown.");
 
             // dupe scene sanity check
             foreach(var key in story.Scenes.Keys)

Ficdown.Parser/Ficdown.Parser.csproj

@@ -12,7 +12,7 @@
   <ItemGroup>
     <PackageReference Include="Epub4Net" Version="1.2.0" />
     <PackageReference Include="Ionic.Zip" Version="1.9.1.8" />
-    <PackageReference Include="MarkdownSharp" Version="2.0.5" />
+    <PackageReference Include="Markdig" Version="0.17.1" />
     <PackageReference Include="System.Text.Encoding.CodePages" Version="4.5.1" />
   </ItemGroup>
 </Project>

Ficdown.Parser/Logger.cs

@@ -0,0 +1,63 @@
+namespace Ficdown.Parser
+{
+    using System;
+    using System.Collections.Generic;
+
+    public class Logger
+    {
+        private static bool _initialized = false;
+        private static bool _debug = false;
+        private static Dictionary<Type, Logger> _cache;
+
+        public Type Type { get; private set; }
+
+        private Logger(Type type)
+        {
+            Type = type;
+        }
+
+        public static void Initialize(bool debug)
+        {
+            _debug = debug;
+            _cache = new Dictionary<Type, Logger>();
+            _initialized = true;
+        }
+
+        public static Logger GetLogger<T>()
+        {
+            var type = typeof(T);
+            lock(_cache)
+            {
+                if(!_cache.ContainsKey(type))
+                    _cache.Add(type, new Logger(type));
+            }
+            return _cache[type];
+        }
+
+        private string Decorate(string message)
+        {
+            return $"{DateTime.Now.ToString("")} <{Type.Name}> {message}";
+        }
+
+        public void Raw(string message)
+        {
+            Console.WriteLine(message);
+        }
+
+        public void Log(string message)
+        {
+            Raw(Decorate(message));
+        }
+
+        public void Debug(string message)
+        {
+            if(!_debug) return;
+            Log($"DEBUG: {message}");
+        }
+
+        public void Error(string message, Exception ex = null)
+        {
+            Console.Error.WriteLine(Decorate($"ERROR: {message}"));
+        }
+    }
+}

Ficdown.Parser/Model/Player/PageState.cs

@@ -7,6 +7,8 @@
 
     internal class PageState
     {
+        public StateManager Manager { get; set; }
+
         public Guid Id { get; set; }
         public Scene Scene { get; set; }
         public State State { get; set; }
@@ -21,12 +23,12 @@ internal class PageState
 
         public string UniqueHash
         {
-            get { return _uniqueHash ?? (_uniqueHash = StateManager.GetUniqueHash(State, Scene.Key)); }
+            get { return _uniqueHash ?? (_uniqueHash = Manager.GetUniqueHash(State, Scene.Key)); }
         }
 
         public string CompressedHash
         {
-            get { return _compressedHash ?? (_compressedHash = StateManager.GetCompressedHash(this)); }
+            get { return _compressedHash ?? (_compressedHash = Manager.GetCompressedHash(this)); }
         }
     }
-}
+}

Ficdown.Parser/Parser/StateResolver.cs

@@ -10,6 +10,7 @@
 
     internal class StateResolver : IStateResolver
     {
+        private static Logger _logger = Logger.GetLogger<StateResolver>();
         private static readonly Random _random = new Random((int) DateTime.Now.Ticks);
         private readonly IDictionary<string, string> _pageNames;
         private readonly HashSet<string> _usedNames;
@@ -25,6 +26,7 @@ public StateResolver()
 
         public ResolvedStory Resolve(IEnumerable<PageState> pages, Story story)
         {
+            _logger.Debug("Resolving story paths...");
             _story = story;
             return new ResolvedStory
             {

Ficdown.Parser/Parser/Utilities.cs

@@ -9,6 +9,15 @@ internal class Utilities
     {
         private List<FicdownException> _warnings { get; set; }
 
+        public static Utilities GetInstance()
+        {
+            return new Utilities
+            {
+                _warnings = new List<FicdownException>(),
+                _blockName = string.Empty
+            };
+        }
+
         public static Utilities GetInstance(List<FicdownException> warnings, string blockName, int lineNumber)
         {
             return new Utilities

Ficdown.Parser/Player/GameTraverser.cs

@@ -11,6 +11,7 @@
 
     internal class GameTraverser : IGameTraverser
     {
+        private static Logger _logger = Logger.GetLogger<GameTraverser>();
         private StateManager _manager;
         private Queue<StateQueueItem> _processingQueue;
         private IDictionary<string, PageState> _processed;
@@ -59,13 +60,15 @@ public IEnumerable<PageState> Enumerate()
             _wasRun = true;
 
             // generate comprehensive enumeration
+            _logger.Debug("Enumerating story scenes...");
 
             var initial = _manager.InitialState;
             _processingQueue.Enqueue(new StateQueueItem
             {
                 Page = initial,
                 AffectedStates = new List<State> {initial.AffectedState}
             });
+            var interval = 0;
             while (_processingQueue.Count > 0)
             {
                 var state = _processingQueue.Dequeue();
@@ -74,9 +77,13 @@ public IEnumerable<PageState> Enumerate()
                     _processed.Add(state.Page.UniqueHash, state.Page);
                     ProcessState(state);
                 }
+
+                if(++interval % 100 == 0 || _processingQueue.Count == 0)
+                    _logger.Debug($"Processed {interval} scenes, {_processingQueue.Count} queued...");
             }
 
             // make sure every page gets affected data on every page that it links to
+            _logger.Debug("Processing scene links...");
             foreach (var pageTuple in _processed)
             {
                 foreach (var linkTuple in pageTuple.Value.Links)
@@ -95,6 +102,7 @@ public IEnumerable<PageState> Enumerate()
             }
 
             // compress redundancies
+            _logger.Debug("Compressing redundant scenes...");
             foreach (var row in _processed)
             {
                 if (!_compressed.ContainsKey(row.Value.CompressedHash))

Ficdown.Parser/Player/StateManager.cs

@@ -11,10 +11,12 @@
 
     internal class StateManager
     {
+        private static Logger _logger = Logger.GetLogger<StateManager>();
         private readonly Story _story;
         private readonly Dictionary<string, int> _stateMatrix;
         private readonly int _sceneCount;
         private readonly int _actionCount;
+        private BitArray _scenesSeenMask;
 
         private List<FicdownException> _warnings { get; set; }
 
@@ -24,6 +26,18 @@ public StateManager(Story story, List<FicdownException> warnings)
             _story = story;
             var allScenes = _story.Scenes.SelectMany(s => s.Value);
             _sceneCount = allScenes.Max(s => s.Id);
+            _scenesSeenMask = new BitArray(_sceneCount);
+
+            // figure out which scenes can affect state
+            var masked = 0;
+            foreach(var scene in allScenes)
+            {
+                if(Utilities.GetInstance().ParseAnchors(scene.RawDescription).Any(a => a.Href.Toggles != null) || RegexLib.BlockQuotes.IsMatch(scene.RawDescription))
+                {
+                    _scenesSeenMask[scene.Id - 1] = true;
+                    masked++;
+                }
+            }
             _actionCount = _story.Actions.Count > 0 ? _story.Actions.Max(a => a.Value.Id) : 0;
             _stateMatrix = new Dictionary<string, int>();
             var state = 0;
@@ -40,6 +54,9 @@ var toggle in
             {
                 _stateMatrix.Add(toggle, state++);
             }
+            _logger.Debug($"{_sceneCount} scenes ({masked} can change state).");
+            _logger.Debug($"{_actionCount} actions.");
+            _logger.Debug($"{_stateMatrix.Count()} states.");
         }
 
         public PageState InitialState
@@ -54,6 +71,8 @@ public PageState InitialState
 
                 return new PageState
                 {
+                    Manager = this,
+
                     Id = Guid.Empty,
                     Links = new Dictionary<string, string>(),
                     State = new State
@@ -119,26 +138,30 @@ public void ToggleSeenSceneOn(State state, int sceneId)
             state.ScenesSeen[sceneId - 1] = true;
         }
 
-        public static string GetUniqueHash(State state, string sceneKey)
+        public string GetUniqueHash(State state, string sceneKey)
         {
             var combined =
                 new bool[
                     state.PlayerState.Count + state.ScenesSeen.Count + state.ActionsToShow.Count +
                     (state.ActionFirstToggles != null ? state.ActionFirstToggles.Count : 0)];
             state.PlayerState.CopyTo(combined, 0);
-            state.ScenesSeen.CopyTo(combined, state.PlayerState.Count);
+            state.ScenesSeen.And(_scenesSeenMask).CopyTo(combined, state.PlayerState.Count);
             state.ActionsToShow.CopyTo(combined, state.PlayerState.Count + state.ScenesSeen.Count);
             if (state.ActionFirstToggles != null)
                 state.ActionFirstToggles.CopyTo(combined,
                     state.PlayerState.Count + state.ScenesSeen.Count + state.ActionsToShow.Count);
             var ba = new BitArray(combined);
             var byteSize = (int)Math.Ceiling(combined.Length / 8.0);
             var encoded = new byte[byteSize];
+            for(var i = 0; i < byteSize; i++)
+            {
+                encoded[i] = 0;
+            }
             ba.CopyTo(encoded, 0);
             return string.Format("{0}=={1}", sceneKey, Convert.ToBase64String(encoded));
         }
 
-        public static string GetCompressedHash(PageState page)
+        public string GetCompressedHash(PageState page)
         {
             var compressed = new State
             {
@@ -187,6 +210,8 @@ private PageState ClonePage(PageState page)
         {
             return new PageState
             {
+                Manager = this,
+
                 Id = Guid.NewGuid(),
                 Links = new Dictionary<string, string>(),
                 State = new State