From 91ce3ba5d5b77880bd838d90cc6fd9cf019ae228 Mon Sep 17 00:00:00 2001 From: John Lambert Date: Wed, 11 Feb 2026 17:39:21 -0500 Subject: [PATCH 1/2] fix(LT-22388): null-safety in SaveOnIdle and harden FileTransactionLogger MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit SaveOnIdle crashed with NullReferenceException when m_logger was null (the default state when LCM_TransactionLogPath is unset). The 1-second timer fires, passes all guards, then dereferences m_logger without a null-conditional operator — unlike every other call site in the same file. UnitOfWorkService: - SaveOnIdle L260: m_logger.AddBreadCrumb → m_logger?.AddBreadCrumb FileTransactionLogger (additional hardening): - Guard AddBreadCrumb against null description (prevents NRE on string concat / ToCharArray) - Add disposed-check with double-lock pattern so the timer-thread race against Dispose does not throw ObjectDisposedException - Replace fire-and-forget WriteAsync with synchronous Write+Flush; fix byte-count bug (old code used description.Length+1, truncating on Windows where Environment.NewLine is 2 chars) - Null out m_stream on dispose; make m_lock readonly Tests (4 new, all verified red-then-green): - SaveOnIdle_LoggerNull_DoesNotThrow (regression for LT-22388) - AddBreadCrumb_AfterDispose_DoesNotThrow - AddBreadCrumb_NullDescription_DoesNotThrow - AddBreadCrumb_WritesFullMessageIncludingNewline All 1709 existing tests pass (net462), zero regressions. --- src/SIL.LCModel/FileTransactionLogger.cs | 21 +++-- .../Infrastructure/Impl/UnitOfWorkService.cs | 2 +- .../FileTransactionLoggerTests.cs | 85 +++++++++++++++++++ .../Impl/UnitOfWorkServiceTests.cs | 24 ++++++ 4 files changed, 126 insertions(+), 6 deletions(-) create mode 100644 tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs diff --git a/src/SIL.LCModel/FileTransactionLogger.cs b/src/SIL.LCModel/FileTransactionLogger.cs index 63090368..81c8787e 100644 --- a/src/SIL.LCModel/FileTransactionLogger.cs +++ b/src/SIL.LCModel/FileTransactionLogger.cs @@ -7,8 +7,9 @@ namespace SIL.LCModel { internal class FileTransactionLogger : ITransactionLogger, IDisposable { - private object m_lock = new object(); + private readonly object m_lock = new object(); private FileStream m_stream; + private bool m_disposed; internal FileTransactionLogger(string filePath) { @@ -22,10 +23,15 @@ internal FileTransactionLogger(string filePath) public void AddBreadCrumb(string description) { + if (description == null || m_disposed) + return; lock (m_lock) { - m_stream.WriteAsync(Encoding.UTF8.GetBytes((description + Environment.NewLine).ToCharArray()), 0, - description.Length + 1); + if (m_disposed) + return; + var bytes = Encoding.UTF8.GetBytes(description + Environment.NewLine); + m_stream.Write(bytes, 0, bytes.Length); + m_stream.Flush(); } } @@ -34,8 +40,13 @@ protected virtual void Dispose(bool disposing) Debug.WriteLineIf(!disposing, "****** Missing Dispose() call for " + GetType() + ". *******"); lock (m_lock) { - m_stream?.Flush(); - m_stream?.Dispose(); + if (!m_disposed) + { + m_stream?.Flush(); + m_stream?.Dispose(); + m_stream = null; + m_disposed = true; + } } } diff --git a/src/SIL.LCModel/Infrastructure/Impl/UnitOfWorkService.cs b/src/SIL.LCModel/Infrastructure/Impl/UnitOfWorkService.cs index f29899d7..0da54f4b 100644 --- a/src/SIL.LCModel/Infrastructure/Impl/UnitOfWorkService.cs +++ b/src/SIL.LCModel/Infrastructure/Impl/UnitOfWorkService.cs @@ -257,7 +257,7 @@ void SaveOnIdle(object sender, ElapsedEventArgs e) // If it is less than 2s since the user did something don't save to smooth performance (unless the user has been busy as a beaver for more than 5 minutes) if (now - m_ui.LastActivityTime < TimeSpan.FromSeconds(2.0) && now < (m_lastSave + TimeSpan.FromMinutes(5))) return; - m_logger.AddBreadCrumb("Saving from SaveOnIdle"); + m_logger?.AddBreadCrumb("Saving from SaveOnIdle"); SaveInternal(); } } diff --git a/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs b/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs new file mode 100644 index 00000000..d496c870 --- /dev/null +++ b/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs @@ -0,0 +1,85 @@ +// Copyright (c) 2026 SIL International +// This software is licensed under the LGPL, version 2.1 or later +// (http://www.gnu.org/licenses/lgpl-2.1.html) + +using System; +using System.IO; +using System.Text; +using NUnit.Framework; + +namespace SIL.LCModel +{ + [TestFixture] + public class FileTransactionLoggerTests + { + private string m_tempFile; + + [SetUp] + public void Setup() + { + m_tempFile = Path.GetTempFileName(); + } + + [TearDown] + public void Teardown() + { + try + { + if (File.Exists(m_tempFile)) + File.Delete(m_tempFile); + } + catch + { + // best-effort cleanup + } + } + + /// + /// After Dispose(), calling AddBreadCrumb must not throw ObjectDisposedException. + /// In production the timer thread can race against Dispose. + /// + [Test] + public void AddBreadCrumb_AfterDispose_DoesNotThrow() + { + var logger = new FileTransactionLogger(m_tempFile); + logger.Dispose(); + + Assert.DoesNotThrow(() => logger.AddBreadCrumb("late write")); + } + + /// + /// Passing a null description must not throw NullReferenceException. + /// + [Test] + public void AddBreadCrumb_NullDescription_DoesNotThrow() + { + using (var logger = new FileTransactionLogger(m_tempFile)) + { + Assert.DoesNotThrow(() => logger.AddBreadCrumb(null)); + } + } + + /// + /// The full message including newline must be written, not truncated. + /// On Windows Environment.NewLine is "\r\n" (2 chars) but old code used + /// description.Length + 1, losing the final byte. + /// + [Test] + public void AddBreadCrumb_WritesFullMessageIncludingNewline() + { + const string message = "hello"; + using (var logger = new FileTransactionLogger(m_tempFile)) + { + logger.AddBreadCrumb(message); + } + + // Wait briefly for async write, then read + System.Threading.Thread.Sleep(200); + + string content = File.ReadAllText(m_tempFile, Encoding.UTF8); + string expected = message + Environment.NewLine; + Assert.AreEqual(expected, content, + "AddBreadCrumb should write the full message plus Environment.NewLine"); + } + } +} diff --git a/tests/SIL.LCModel.Tests/Infrastructure/Impl/UnitOfWorkServiceTests.cs b/tests/SIL.LCModel.Tests/Infrastructure/Impl/UnitOfWorkServiceTests.cs index 0a5e1c67..9d8479d5 100644 --- a/tests/SIL.LCModel.Tests/Infrastructure/Impl/UnitOfWorkServiceTests.cs +++ b/tests/SIL.LCModel.Tests/Infrastructure/Impl/UnitOfWorkServiceTests.cs @@ -26,6 +26,30 @@ public void SaveOnIdle_UiCleared_DoesNotThrow() InvokeNonPublicVoid(serviceInstance, "SaveOnIdle", null, null)); } + /// + /// Regression test: m_logger is null by default (no LCM_TransactionLogPath env var). + /// SaveOnIdle must use null-conditional on m_logger.AddBreadCrumb to avoid NRE. + /// Reproduces the crash reported in LT-22388. + /// + [Test] + public void SaveOnIdle_LoggerNull_DoesNotThrow() + { + var uowService = Cache.ServiceLocator.GetInstance(); + var serviceInstance = (object)uowService; + + InvokeNonPublicVoid(serviceInstance, "StopSaveTimer"); + + // Force m_logger to null (default production state when LCM_TransactionLogPath is unset) + SetNonPublicField(serviceInstance, "m_logger", null); + + // Force m_lastSave far enough in the past to pass BOTH the 10-second guard + // AND the 5-minute "busy beaver" clause so we actually reach m_logger.AddBreadCrumb + SetNonPublicField(serviceInstance, "m_lastSave", DateTime.Now.AddMinutes(-10)); + + Assert.DoesNotThrow(() => + InvokeNonPublicVoid(serviceInstance, "SaveOnIdle", null, null)); + } + private static void SetNonPublicField(object instance, string fieldName, object value) { var field = instance.GetType().GetField(fieldName, BindingFlags.Instance | BindingFlags.NonPublic); From 141c01d42b4ef5a49d9fdd5e9f3c24ba9b34e5eb Mon Sep 17 00:00:00 2001 From: John Lambert Date: Wed, 11 Feb 2026 18:57:15 -0500 Subject: [PATCH 2/2] fix: restore async WriteAsync with proper write chaining Address PR review feedback: - Restore fire-and-forget WriteAsync per reviewer request (jasonleenaylor) - Chain writes via ContinueWith/Unwrap to prevent overlapping async writes on the same stream - Use bytes.Length for correct byte count (fixes truncation on Windows where Environment.NewLine is 2 chars) - Dispose waits for pending writes via GetAwaiter().GetResult() before flushing and closing the stream - Remove unnecessary Thread.Sleep(200) from test; Dispose guarantees writes are complete --- src/SIL.LCModel/FileTransactionLogger.cs | 9 +++++++-- tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs | 4 +--- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/src/SIL.LCModel/FileTransactionLogger.cs b/src/SIL.LCModel/FileTransactionLogger.cs index 81c8787e..3e4ebf89 100644 --- a/src/SIL.LCModel/FileTransactionLogger.cs +++ b/src/SIL.LCModel/FileTransactionLogger.cs @@ -2,6 +2,7 @@ using System.Diagnostics; using System.IO; using System.Text; +using System.Threading.Tasks; namespace SIL.LCModel { @@ -9,6 +10,7 @@ internal class FileTransactionLogger : ITransactionLogger, IDisposable { private readonly object m_lock = new object(); private FileStream m_stream; + private Task m_lastWrite = Task.CompletedTask; private bool m_disposed; internal FileTransactionLogger(string filePath) @@ -30,8 +32,9 @@ public void AddBreadCrumb(string description) if (m_disposed) return; var bytes = Encoding.UTF8.GetBytes(description + Environment.NewLine); - m_stream.Write(bytes, 0, bytes.Length); - m_stream.Flush(); + m_lastWrite = m_lastWrite.ContinueWith(_ => + m_stream.WriteAsync(bytes, 0, bytes.Length), + TaskContinuationOptions.ExecuteSynchronously).Unwrap(); } } @@ -42,6 +45,8 @@ protected virtual void Dispose(bool disposing) { if (!m_disposed) { + try { m_lastWrite?.GetAwaiter().GetResult(); } + catch { /* best-effort: don't let a failed write prevent disposal */ } m_stream?.Flush(); m_stream?.Dispose(); m_stream = null; diff --git a/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs b/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs index d496c870..6a21767f 100644 --- a/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs +++ b/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs @@ -73,9 +73,7 @@ public void AddBreadCrumb_WritesFullMessageIncludingNewline() logger.AddBreadCrumb(message); } - // Wait briefly for async write, then read - System.Threading.Thread.Sleep(200); - + // Dispose flushes the stream, so the file is readable immediately. string content = File.ReadAllText(m_tempFile, Encoding.UTF8); string expected = message + Environment.NewLine; Assert.AreEqual(expected, content,