Skip to content

Conversation

@johnml1135
Copy link
Contributor

@johnml1135 johnml1135 commented Feb 11, 2026

Problem

FieldWorks crashes with NullReferenceException ~10 seconds after launch when the 1-second idle-save timer fires in UnitOfWorkService.SaveOnIdle.

Root cause: m_logger.AddBreadCrumb(...) on line 260 dereferences m_logger without a null-conditional operator. In production, m_logger is null by default (only set when LCM_TransactionLogPath env var is configured). Every other m_logger call site in the same file already uses ?. operator.

Changes

UnitOfWorkService.cs

  • m_logger.AddBreadCrumb -> m_logger?.AddBreadCrumb in SaveOnIdle

FileTransactionLogger.cs (hardening)

Audited the logger called by SaveOnIdle and found 3 additional bugs:

  1. Use-after-dispose: AddBreadCrumb after Dispose() throws ObjectDisposedException (timer thread can race against shutdown). Fixed with m_disposed flag + double-check lock pattern.
  2. Null description: AddBreadCrumb(null) throws NRE on .ToCharArray(). Added null guard.
  3. Byte count truncation: Old code used WriteAsync with description.Length+1 as the byte count, but Environment.NewLine is 2 chars on Windows, truncating the last byte. Replaced with synchronous Write(bytes, 0, bytes.Length) + Flush() for correctness.
  4. Made m_lock readonly; null out m_stream on dispose.

Tests (4 new, all verified red-then-green)

  • SaveOnIdle_LoggerNull_DoesNotThrow - regression test for LT-22388
  • AddBreadCrumb_AfterDispose_DoesNotThrow - timer/dispose race
  • AddBreadCrumb_NullDescription_DoesNotThrow - null safety
  • AddBreadCrumb_WritesFullMessageIncludingNewline - correct byte output

Verification

All 1709 tests pass (net462), zero failures, zero regressions.


This change is Reviewable

…gger

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.
Copilot AI review requested due to automatic review settings February 11, 2026 22:43
Copy link

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Fixes a startup crash caused by UnitOfWorkService.SaveOnIdle dereferencing a null transaction logger, and hardens FileTransactionLogger against dispose races and null inputs.

Changes:

  • Use null-conditional logging in UnitOfWorkService.SaveOnIdle to prevent NullReferenceException when m_logger is unset.
  • Harden FileTransactionLogger.AddBreadCrumb for dispose races and null descriptions; adjust write logic to avoid newline truncation.
  • Add regression/unit tests covering the null-logger SaveOnIdle scenario and FileTransactionLogger edge cases.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 2 comments.

File Description
src/SIL.LCModel/Infrastructure/Impl/UnitOfWorkService.cs Prevents null dereference by using m_logger?.AddBreadCrumb in SaveOnIdle.
src/SIL.LCModel/FileTransactionLogger.cs Adds dispose/null guards and changes write strategy to write full newline-terminated messages.
tests/SIL.LCModel.Tests/Infrastructure/Impl/UnitOfWorkServiceTests.cs Adds regression test ensuring SaveOnIdle doesn’t throw when m_logger is null.
tests/SIL.LCModel.Tests/FileTransactionLoggerTests.cs Adds tests for dispose race safety, null description, and correct message output.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

return;
var bytes = Encoding.UTF8.GetBytes(description + Environment.NewLine);
m_stream.Write(bytes, 0, bytes.Length);
m_stream.Flush();
Copy link

Copilot AI Feb 11, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

AddBreadCrumb now performs a synchronous Write followed by Flush() on every call. This can introduce significant I/O overhead and potentially block the calling thread (e.g., during save/notification paths) whenever transaction logging is enabled. Consider keeping the corrected byte-length logic but avoiding per-call flushing (flush on dispose/periodically) or using buffered/asynchronous writes so logging doesn’t impact runtime performance.

Suggested change
m_stream.Flush();

Copilot uses AI. Check for mistakes.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@copilot[bot] This needs to remain Async

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch — restored WriteAsync as requested. The updated implementation:

  • Keeps fire-and-forget WriteAsync (non-blocking for callers)
  • Fixes the byte count bug (bytes.Length instead of description.Length + 1)
  • Chains writes via ContinueWith/Unwrap so concurrent AddBreadCrumb calls don't overlap on the stream
  • Removes per-call Flush() — flushing now happens only on Dispose
  • Dispose waits for the last pending write via GetAwaiter().GetResult() before closing the stream

This keeps the async I/O pattern while fixing correctness and safety.

Comment on lines 76 to 78
// Wait briefly for async write, then read
System.Threading.Thread.Sleep(200);

Copy link

Copilot AI Feb 11, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test still waits for an “async write” via Thread.Sleep(200), but FileTransactionLogger.AddBreadCrumb is now synchronous and flushes before returning. The sleep is unnecessary and slows the test suite; the comment is also now misleading.

Suggested change
// Wait briefly for async write, then read
System.Threading.Thread.Sleep(200);
// AddBreadCrumb flushes synchronously; the file can be read immediately.

Copilot uses AI. Check for mistakes.
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed — removed Thread.Sleep(200) and updated the comment. Dispose now waits for all pending async writes via GetAwaiter().GetResult() before flushing and closing the stream, so the file is readable immediately after Dispose returns. No artificial delay needed.

return;
var bytes = Encoding.UTF8.GetBytes(description + Environment.NewLine);
m_stream.Write(bytes, 0, bytes.Length);
m_stream.Flush();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@copilot[bot] This needs to remain Async

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
Copy link
Contributor

@jasonleenaylor jasonleenaylor left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:lgtm:

@jasonleenaylor reviewed 4 files and all commit messages, and made 1 comment.
Reviewable status: all files reviewed, 2 unresolved discussions (waiting on @johnml1135).

@jasonleenaylor jasonleenaylor merged commit 766b9ac into sillsdev:master Feb 12, 2026
3 of 4 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants