Merge pull request connamara#966 from gbirchmeier/nonsessionlog-concurrency

fix connamara#963 NonSessionLog concurrency bug on Windows

Author: gbirchmeier

QuickFIXn/Logger/NonSessionLog.cs

@@ -4,34 +4,31 @@ namespace QuickFix.Logger;
 /// A logger that can be used when the calling logic cannot identify a session (which is rare).
 /// Does not create a log artifact until first write.
 /// </summary>
-public class NonSessionLog : System.IDisposable {
+public class NonSessionLog {
 
     private readonly ILogFactory _logFactory;
-    private ILog? _log;
 
-    private readonly object _sync = new();
+    private readonly static object _sync = new();
 
     internal NonSessionLog(ILogFactory logFactory) {
         _logFactory = logFactory;
     }
 
+    /// <summary>
+    /// Write to a log that is not tied to a session.
+    /// Calls to this should be rare, and only to record problem events that
+    /// cannot be tied to a specific session.
+    /// (Think errors and maybe warnings, NOT infos.)
+    /// </summary>
+    /// <param name="s">message to log</param>
     internal void OnEvent(string s) {
-        if (_disposed) return;
-
+        // Atomic open/write/close operation.
+        // This function should not be called often enough
+        //   for this overhead to cause a performance issue.
         lock (_sync) {
-            _log ??= _logFactory.CreateNonSessionLog();
-        }
-        _log?.OnEvent(s);
-    }
-
-    private bool _disposed;
-    public void Dispose() {
-        if (_disposed) return;
-
-        if (_log != null) {
+            ILog _log = _logFactory.CreateNonSessionLog();
+            _log.OnEvent(s);
             _log.Dispose();
-            _log = null;
-            _disposed = true;
         }
     }
 }

QuickFIXn/ThreadedSocketAcceptor.cs

@@ -274,7 +274,6 @@ public void Stop(bool force)
             LogoutAllSessions(force);
             DisposeSessions();
             _sessions.Clear();
-            _nonSessionLog.Dispose();
             _isStarted = false;
 
             // FIXME StopSessionTimer();

RELEASE_NOTES.md

@@ -42,6 +42,7 @@ What's New
 * #942 - fix #942: field 369 (LastMsgSeqNumProcessed) wrong in ResendRequest message (gbirchmeier)
 * #940 - Create an alternate CharEncoding.GetBytes impl which uses ArrayPool to improve memory performance (VAllens)
 * #951 - fix: restore Session disconnect during SocketInitiatorThread.Read exception (gbirchmeier/trevor-bush)
+* #963 - fix: concurrency bug with NonSessionLog on Windows (gbirchmeier)
 
 ### v1.13.1
 * backport #951 to 1.13

UnitTests/Logger/NonSessionLogTests.cs

@@ -5,19 +5,17 @@
 namespace UnitTests.Logger;
 
 [TestFixture]
-public class NonSessionLogTests {
+public class NonSessionLogTests
+{
     private readonly string _logDirectory = Path.Combine(TestContext.CurrentContext.TestDirectory, "log");
 
-    private NonSessionLog? _nslog;
-
     [TearDown]
     public void Teardown()
     {
-        _nslog?.Dispose();
-        _nslog = null;
     }
-    
-    private FileLogFactory CreateFileLogFactory() {
+
+    private FileLogFactory CreateFileLogFactory()
+    {
         if (Directory.Exists(_logDirectory))
             Directory.Delete(_logDirectory, true);
 
@@ -32,47 +30,59 @@ private FileLogFactory CreateFileLogFactory() {
                                TargetCompID=TARGETCOMP
                                """;
 
-        QuickFix.SessionSettings settings = new QuickFix.SessionSettings(
+        QuickFix.SessionSettings settings = new(
             new StringReader(configString));
 
         return new FileLogFactory(settings);
     }
 
     [Test]
-    public void TestWithFileLogFactory() {
+    public void TestWithFileLogFactory()
+    {
         FileLogFactory flf = CreateFileLogFactory();
-        _nslog = new NonSessionLog(flf);
+        NonSessionLog nslog = new(flf);
 
         // Log artifact not created before first log-write
         Assert.That(Directory.Exists(_logDirectory), Is.False);
 
         // Log artifact exists after first log-write
-        _nslog.OnEvent("some text");
+        nslog.OnEvent("some text");
         Assert.That(Directory.Exists(_logDirectory));
         Assert.That(File.Exists(Path.Combine(_logDirectory, "Non-Session-Log.event.current.log")));
 
         // cleanup (don't delete log unless success)
-        _nslog.Dispose();
-        _nslog = null;
         Directory.Delete(_logDirectory, true);
     }
 
     [Test]
-    public void TestWithCompositeLogFactory() {
+    public void TestTwoFileLogs()
+    {
+        FileLogFactory flf = CreateFileLogFactory();
+        NonSessionLog nslog = new(flf);
+        nslog.OnEvent("log1");
+
+        NonSessionLog nslog2 = new(flf);
+        nslog2.OnEvent("log2");
+
+        // cleanup (don't delete log unless success)
+        Directory.Delete(_logDirectory, true);
+    }
+
+    [Test]
+    public void TestWithCompositeLogFactory()
+    {
         CompositeLogFactory clf = new CompositeLogFactory([CreateFileLogFactory(), new NullLogFactory()]);
-        _nslog = new NonSessionLog(clf);
+        NonSessionLog nslog = new(clf);
 
         // Log artifact not created before first log-write
         Assert.That(Directory.Exists(_logDirectory), Is.False);
 
         // Log artifact exists after first log-write
-        _nslog.OnEvent("some text");
+        nslog.OnEvent("some text");
         Assert.That(Directory.Exists(_logDirectory));
         Assert.That(File.Exists(Path.Combine(_logDirectory, "Non-Session-Log.event.current.log")));
 
         // cleanup (don't delete log unless success)
-        _nslog.Dispose();
-        _nslog = null;
         Directory.Delete(_logDirectory, true);
     }
 }