diff --git a/src/SIL.LCModel/FileTransactionLogger.cs b/src/SIL.LCModel/FileTransactionLogger.cs index 63090368..3e4ebf89 100644 --- a/src/SIL.LCModel/FileTransactionLogger.cs +++ b/src/SIL.LCModel/FileTransactionLogger.cs @@ -2,13 +2,16 @@ using System.Diagnostics; using System.IO; using System.Text; +using System.Threading.Tasks; 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 Task m_lastWrite = Task.CompletedTask; + private bool m_disposed; internal FileTransactionLogger(string filePath) { @@ -22,10 +25,16 @@ 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_lastWrite = m_lastWrite.ContinueWith(_ => + m_stream.WriteAsync(bytes, 0, bytes.Length), + TaskContinuationOptions.ExecuteSynchronously).Unwrap(); } } @@ -34,8 +43,15 @@ 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) + { + 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; + 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..6a21767f --- /dev/null +++ b/tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs @@ -0,0 +1,83 @@ +// 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); + } + + // 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, + "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);