From 147c544496b4f3c6b4eb3cdcb69f117aa445ba4d Mon Sep 17 00:00:00 2001 From: dh Date: Sat, 3 Oct 2026 22:44:31 +0200 Subject: [PATCH] ci: observe transcript append failure and Windows reader sharing --- .gitea/workflows/pr-push-build-and-test.yaml | 9 ++ .../RecordingCoordinatorTests.cs | 151 ++++++++++++++++-- tools/ci/TranscriptFileShareProbe.cs | 88 ++++++++++ tools/ci/TranscriptFileShareProbe.md | 25 +++ 4 files changed, 261 insertions(+), 12 deletions(-) create mode 100644 tools/ci/TranscriptFileShareProbe.cs create mode 100644 tools/ci/TranscriptFileShareProbe.md diff --git a/.gitea/workflows/pr-push-build-and-test.yaml b/.gitea/workflows/pr-push-build-and-test.yaml index 789a0c0..9988ebe 100644 --- a/.gitea/workflows/pr-push-build-and-test.yaml +++ b/.gitea/workflows/pr-push-build-and-test.yaml @@ -112,6 +112,15 @@ jobs: --nologo test -s MeetingAssistant/bin/Release/net10.0-windows10.0.19041.0/win-x64/MeetingAssistant.dll + - name: Measure transcript reader sharing on the Windows Wine host + run: | + mkdir -p artifacts/tests + transcript_probe_exit=0 + "${WINE_BIN}" "${WIN_DOTNET_DIR}/dotnet.exe" run \ + --file tools/ci/TranscriptFileShareProbe.cs > artifacts/tests/transcript-file-sharing.json || transcript_probe_exit=$? + cat artifacts/tests/transcript-file-sharing.json + exit "${transcript_probe_exit}" + - name: Run tests via Wine (Windows dotnet host) run: | rm -f artifacts/tests/wine.trx diff --git a/MeetingAssistant.Tests/RecordingCoordinatorTests.cs b/MeetingAssistant.Tests/RecordingCoordinatorTests.cs index ce2928f..52560bd 100644 --- a/MeetingAssistant.Tests/RecordingCoordinatorTests.cs +++ b/MeetingAssistant.Tests/RecordingCoordinatorTests.cs @@ -191,18 +191,21 @@ public sealed class RecordingCoordinatorTests NullLogger.Instance); var artifactStore = new MarkdownMeetingArtifactStore( NullLogger.Instance); + var writeProbe = new TranscriptWriteDiagnostic(); + var transcriptStore = new DiagnosticTranscriptStore( + new VaultTranscriptStore(Options.Create(options), NullLogger.Instance), + writeProbe); var coordinator = new MeetingRecordingCoordinator( audioSource, new TestSpeechRecognitionPipelineFactory( - new FixedSegmentStreamingTranscriptionProvider( - new TranscriptionSegment( - TimeSpan.FromSeconds(4), - TimeSpan.FromSeconds(5), - "Guest-1", - "Azure returned ***** here."))), - new VaultTranscriptStore( - Options.Create(options), - NullLogger.Instance), + new DiagnosticTranscriptionProvider( + new FixedSegmentStreamingTranscriptionProvider( + new TranscriptionSegment( + TimeSpan.FromSeconds(4), + TimeSpan.FromSeconds(5), + "Guest-1", + "Azure returned ***** here.")), writeProbe)), + transcriptStore, noteStore, new CapturingMeetingNoteOpener(), artifactStore, @@ -218,9 +221,45 @@ public sealed class RecordingCoordinatorTests NullLogger.Instance)); var started = await coordinator.StartAsync(CancellationToken.None); - await audioSource.WriteAsync(new AudioChunk([1, 0], 16000, 1), CancellationToken.None); - await WaitUntilAsync(() => FileContainsText(started.TranscriptPath!, "Azure returned")); - await coordinator.StopAsync(CancellationToken.None); + Exception? waitFailure = null; + Exception? stopFailure = null; + try + { + await audioSource.WriteAsync(new AudioChunk([1, 0], 16000, 1), CancellationToken.None); + writeProbe.Record("test-audio-enqueued"); + await WaitUntilAsync(() => FileContainsText(started.TranscriptPath!, "Azure returned")); + } + catch (Exception exception) + { + waitFailure = exception; + writeProbe.Record("test-wait-failed", exception); + } + finally + { + try + { + await coordinator.StopAsync(CancellationToken.None); + writeProbe.Record("test-stop-completed"); + } + catch (Exception exception) + { + stopFailure = exception; + writeProbe.Record("test-stop-failed", exception); + } + } + + if (waitFailure is TimeoutException) + { + throw new TimeoutException($"{waitFailure.Message} {writeProbe.Describe()}", waitFailure); + } + if (waitFailure is not null) + { + System.Runtime.ExceptionServices.ExceptionDispatchInfo.Capture(waitFailure).Throw(); + } + if (stopFailure is not null) + { + System.Runtime.ExceptionServices.ExceptionDispatchInfo.Capture(stopFailure).Throw(); + } var content = await File.ReadAllTextAsync(started.TranscriptPath!); Assert.Contains("[00:00:04] Guest-1: Azure returned [redacted] here.", content); @@ -5212,6 +5251,94 @@ public sealed class RecordingCoordinatorTests } } + // Temporary diagnosis of Run4174. Observes public provider/store boundaries only. + private sealed class TranscriptWriteDiagnostic + { + private readonly System.Diagnostics.Stopwatch elapsed = System.Diagnostics.Stopwatch.StartNew(); + private readonly ConcurrentQueue events = new(); + + public void Record(string name, Exception? error = null) + { + events.Enqueue($"{elapsed.ElapsedMilliseconds}ms:{name}" + (error is null ? "" : + $":{error.GetType().FullName}:HResult=0x{error.HResult:X8}:{error.Message}")); + } + + public string Describe() => "[DEBUG-transcript-write-4174] " + string.Join(" | ", events); + } + + private sealed class DiagnosticTranscriptionProvider( + IStreamingTranscriptionProvider inner, + TranscriptWriteDiagnostic probe) : IStreamingTranscriptionProvider + { + public async IAsyncEnumerable TranscribeAsync( + IAsyncEnumerable audio, + SpeechRecognitionPipelineOptions options, + [System.Runtime.CompilerServices.EnumeratorCancellation] CancellationToken cancellationToken) + { + await foreach (var segment in inner.TranscribeAsync(ObserveAudioAsync(audio, cancellationToken), options, cancellationToken)) + { + probe.Record("fake-segment-yielded"); + yield return segment; + } + } + + private async IAsyncEnumerable ObserveAudioAsync( + IAsyncEnumerable audio, + [System.Runtime.CompilerServices.EnumeratorCancellation] CancellationToken cancellationToken) + { + await foreach (var chunk in audio.WithCancellation(cancellationToken)) + { + probe.Record("fake-audio-consumed"); + yield return chunk; + } + } + } + + private sealed class DiagnosticTranscriptStore( + ITranscriptStore inner, + TranscriptWriteDiagnostic probe) : ITranscriptStore + { + public Task CreateSessionAsync(CancellationToken cancellationToken) => + inner.CreateSessionAsync(cancellationToken); + public Task CreateSessionAsync(MeetingAssistantOptions options, DateTimeOffset startedAt, CancellationToken cancellationToken) => + inner.CreateSessionAsync(options, startedAt, cancellationToken); + public Task ReplaceLinesAsync(TranscriptSession session, IReadOnlyList replacementLines, CancellationToken cancellationToken) => + inner.ReplaceLinesAsync(session, replacementLines, cancellationToken); + public Task UpdateMetadataAsync(TranscriptSession session, MeetingSessionArtifacts artifacts, MeetingNote meetingNote, CancellationToken cancellationToken) => + inner.UpdateMetadataAsync(session, artifacts, meetingNote, cancellationToken); + + public async Task AppendLineAsync(TranscriptSession session, string line, CancellationToken cancellationToken) + { + probe.Record("append-entered"); + try + { + var reference = await inner.AppendLineAsync(session, line, cancellationToken); + probe.Record("append-completed"); + return reference; + } + catch (Exception exception) + { + probe.Record("append-failed", exception); + throw; + } + } + + public async Task ReplaceLineAsync(TranscriptSession session, TranscriptLineReference lineReference, string replacementLine, CancellationToken cancellationToken) + { + probe.Record("rewrite-entered"); + try + { + await inner.ReplaceLineAsync(session, lineReference, replacementLine, cancellationToken); + probe.Record("rewrite-completed"); + } + catch (Exception exception) + { + probe.Record("rewrite-failed", exception); + throw; + } + } + } + private sealed class TestSpeechRecognitionPipelineFactory : ISpeechRecognitionPipelineFactory { private readonly IStreamingTranscriptionProvider provider; diff --git a/tools/ci/TranscriptFileShareProbe.cs b/tools/ci/TranscriptFileShareProbe.cs new file mode 100644 index 0000000..b8d669a --- /dev/null +++ b/tools/ci/TranscriptFileShareProbe.cs @@ -0,0 +1,88 @@ +#:property PublishAot=false +// Local diagnostic only. See TranscriptFileShareProbe.md for the contract and limits. +using System.Diagnostics; +using System.Runtime.InteropServices; +using System.Text; +using System.Text.Json; + +const string original = "---\ntitle: transcript probe\n---\n\n# Meeting Transcript\n"; +const string written = original + "[00:00:04] Guest-1: Azure returned ***** here.\n"; +var root = Path.Combine(Path.GetTempPath(), "meeting-assistant-file-share-probe", Guid.NewGuid().ToString("N")); +if (Directory.Exists(root)) + throw new IOException("Probe directory already exists; refusing to reuse it."); +Directory.CreateDirectory(root); +var cases = new List(); +var cleanupCompleted = false; +try +{ + var path = Path.Combine(root, "original-reader.md"); + await File.WriteAllTextAsync(path, original); + using (var reader = new StreamReader(path, Encoding.UTF8, detectEncodingFromByteOrderMarks: true)) + { + if (reader.ReadToEnd() != original) + throw new InvalidDataException("Original reader did not read the initial fixture."); + cases.Add(await ObserveWriteAsync("held-original-reader", path, written)); + } + cases[^1] = cases[^1] with { ContentAfterReaderClosed = await File.ReadAllTextAsync(path) }; + cases.Add(await ObserveWriteAsync("original-reader-released", path, written)); + cases[^1] = cases[^1] with { ContentAfterReaderClosed = await File.ReadAllTextAsync(path) }; + + path = Path.Combine(root, "compatible-reader.md"); + await File.WriteAllTextAsync(path, original); + using (var stream = new FileStream(path, FileMode.Open, FileAccess.Read, FileShare.ReadWrite | FileShare.Delete)) + using (var reader = new StreamReader(stream, Encoding.UTF8, detectEncodingFromByteOrderMarks: true)) + { + if (reader.ReadToEnd() != original) + throw new InvalidDataException("Compatible reader did not read the initial fixture."); + cases.Add(await ObserveWriteAsync("held-compatible-reader", path, written)); + } + cases[^1] = cases[^1] with { ContentAfterReaderClosed = await File.ReadAllTextAsync(path) }; +} +finally +{ + Directory.Delete(root, recursive: true); + cleanupCompleted = !Directory.Exists(root); +} + +var windowsContractMatched = OperatingSystem.IsWindows() + ? !cases[0].Completed && cases[0].Error is { Type: "System.IO.IOException", NativeCode: 32 } + && cases[0].ContentAfterReaderClosed == original + : (bool?)null; +var compatibleAndReleasedWritesCompleted = cases.Skip(1).All(result => + result.Completed && result.Error is null && result.ContentAfterReaderClosed == written); +Console.WriteLine(JsonSerializer.Serialize(new +{ + Schema = "meeting-assistant-file-share-probe/v1", + Runtime = RuntimeInformation.FrameworkDescription, + OS = RuntimeInformation.OSDescription, + Architecture = RuntimeInformation.ProcessArchitecture.ToString(), + ProbeDirectory = root, + CleanupCompleted = cleanupCompleted, + WindowsContractMatched = windowsContractMatched, + CompatibleAndReleasedWritesCompleted = compatibleAndReleasedWritesCompleted, + Cases = cases, + EvidenceLimit = "Held-reader access-mode probe; it does not reproduce the timing or establish the cause of Run4174." +}, new JsonSerializerOptions { WriteIndented = true })); +return cleanupCompleted && compatibleAndReleasedWritesCompleted && windowsContractMatched != false ? 0 : 1; + +static async Task ObserveWriteAsync(string name, string path, string content) +{ + var elapsed = Stopwatch.StartNew(); + Task? write = null; + using var deadline = new CancellationTokenSource(TimeSpan.FromSeconds(5)); + try + { + write = File.WriteAllTextAsync(path, content, deadline.Token); + await write; + return new(name, true, write.Status.ToString(), elapsed.ElapsedMilliseconds, null, null); + } + catch (Exception exception) + { + return new(name, false, write?.Status.ToString() ?? "not-returned", elapsed.ElapsedMilliseconds, + new(exception.GetType().FullName!, $"0x{exception.HResult:X8}", exception.HResult & 0xffff, exception.Message), null); + } +} + +sealed record WriteObservation(string Name, bool Completed, string TaskStatus, long ElapsedMilliseconds, + WriteError? Error, string? ContentAfterReaderClosed); +sealed record WriteError(string Type, string HResult, int NativeCode, string Message); diff --git a/tools/ci/TranscriptFileShareProbe.md b/tools/ci/TranscriptFileShareProbe.md new file mode 100644 index 0000000..ef7aab4 --- /dev/null +++ b/tools/ci/TranscriptFileShareProbe.md @@ -0,0 +1,25 @@ +# Transcript file sharing diagnostic + +Purpose: distinguish a writer error from a completed write when a reader with the original test's access mode remains open. This temporary diagnostic does not change the app, its tests, or their 577-case count. + +Entry point: `tools/ci/TranscriptFileShareProbe.cs`, a .NET 10 file-based app with BCL-only dependencies. From this clone: + +```sh +/Users/dh/.dotnet/dotnet run --file tools/ci/TranscriptFileShareProbe.cs +``` + +On another machine use its .NET 10 SDK executable. The file-based app requires an SDK supporting file-based apps; the prepared local run uses SDK 10.0.401. Native AOT is disabled for this diagnostic so its JSON report can use the normal reflection serializer. It prints JSON with runtime/OS, write completion, exception type/HResult/native error code, content after reader disposal, and cleanup status. It creates a unique directory beneath the system temporary directory, writes two small fixture files, and deletes only that directory in `finally`. It starts no Meeting Assistant app, service, network client, container, or VM. The SDK can create its normal file-based build cache. For a fresh CLI profile set `DOTNET_GENERATE_ASPNET_CERTIFICATE=false` and `DOTNET_CLI_TELEMETRY_OPTOUT=1` to disable unrelated certificate/telemetry initialization. + +The optional instrumentation in the existing recording-coordinator test observes public provider and transcript-store boundaries: audio consumed, fake segment yielded, append/rewrite entered, completed, or failed. Timeout output uses `[DEBUG-transcript-write-4174]` and includes elapsed milliseconds, exception type, HResult, and message. The reader, 15-second wait and final redaction assertions are unchanged. `StopAsync` always runs in `finally`; a stop failure does not mask the original timeout. Timestamps distinguish events before and after the failed wait. Instrumentation can affect race timing; a passing run alone does not explain the original failure. This temporary instrumentation should be removed after the actual Wine incident is explained. + +The original-reader case uses the same path-taking `StreamReader` constructor as `File.ReadAllText`. It deliberately holds the reader after reading the fixture so that the overlap is deterministic. The original test normally disposes that reader immediately after `ReadToEnd`; therefore this probe checks compatible access modes, not the historical race's timing. The second write happens after disposing that reader. The compatible case holds `FileAccess.Read` with `FileShare.ReadWrite | FileShare.Delete`. No reader fix is applied to the actual test. + +The existing Wine job runs this probe after its actual Windows SDK build and before the unchanged full test cohort. It writes `artifacts/tests/transcript-file-sharing.json` and prints that report into the CI log. Invocation there uses the already installed Windows SDK through the existing `WINE_BIN`; no runner or infrastructure capability is added. The measured Wine result is pending until this exact workflow executes. + +## Primary-source contract + +In [.NET runtime v10.0.12 File.cs](https://github.com/dotnet/runtime/blob/v10.0.12/src/libraries/System.Private.CoreLib/src/System/IO/File.cs#L572), `ReadAllText` constructs a path-taking `StreamReader`; [`StreamReader.cs`](https://github.com/dotnet/runtime/blob/v10.0.12/src/libraries/System.Private.CoreLib/src/System/IO/StreamReader.cs#L203) opens read access sharing only further readers. `WriteAllTextAsync` delegates to a create-mode write; [its writer](https://github.com/dotnet/runtime/blob/v10.0.12/src/libraries/System.Private.CoreLib/src/System/IO/File.cs#L1416) opens write access with reader sharing. + +[Windows CreateFileW documentation](https://learn.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-createfilew#parameters) requires existing access and sharing modes to remain compatible until handle closure. A held reader that does not permit writes therefore prevents that writer from opening; the Windows contract expects an `IOException` with sharing-violation native code 32. Allowing read/write sharing removes that incompatibility. Delete sharing is included for the comparison but this probe does not rename or delete an open file. + +On Windows the CLI asserts that the original held-reader write fails with code 32 and leaves the original bytes, and that both subsequent writes complete with the expected content. On other platforms it reports the original-reader observation without asserting Windows behavior (`WindowsContractMatched: null`), and still checks completed compatible/released writes and cleanup. The Unix/macOS implementation can differ. A local macOS success is not evidence of Wine behavior or the cause of Run4174's timeout.