Failing Test `HttpLogging.FileLoggerProcessorTests.WritesToNewFileOnOptionsChange`

[TanayParikh]

Failing Test(s)

• Microsoft.AspNetCore.HttpLogging.FileLoggerProcessorTests.WritesToNewFileOnOptionsChange

Error Message

Assert.Equal() Failure
↓ (pos 0)
Expected: Message two

Actual:

↑ (pos 0)

Stacktrace

   at Microsoft.AspNetCore.HttpLogging.FileLoggerProcessorTests.WritesToNewFileOnOptionsChange() in /_/src/Middleware/HttpLogging/test/FileLoggerProcessorTests.cs:line 386
--- End of stack trace from previous location ---

Logs

[xUnit.net 00:00:02.26]     Microsoft.AspNetCore.HttpLogging.FileLoggerProcessorTests.WritesToNewFileOnOptionsChange [FAIL]
[xUnit.net 00:00:02.26]       Assert.Equal() Failure
[xUnit.net 00:00:02.26]                 ↓ (pos 0)
[xUnit.net 00:00:02.26]       Expected: Message two\n
[xUnit.net 00:00:02.26]       Actual:   
[xUnit.net 00:00:02.26]                 ↑ (pos 0)
[xUnit.net 00:00:02.26]       Stack Trace:
[xUnit.net 00:00:02.26]         /_/src/Middleware/HttpLogging/test/FileLoggerProcessorTests.cs(386,0): at Microsoft.AspNetCore.HttpLogging.FileLoggerProcessorTests.WritesToNewFileOnOptionsChange()
[xUnit.net 00:00:02.26]         --- End of stack trace from previous location ---
[xUnit.net 00:00:03.08]   Finished:    Microsoft.AspNetCore.HttpLogging.Tests

Build

https://dev.azure.com/dnceng/public/_build/results?buildId=1272695&view=ms.vss-test-web.build-test-results-tab&runId=37642180&resultId=108945&paneView=dotnet-dnceng.dnceng-build-release-tasks.helix-test-information-tab

Thanks for contacting us.

We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We would like to keep this around to collect more feedback, which can help us with prioritizing this work. We will re-evaluate this issue, during our next planning meeting(s).
If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues.
To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

[wtgodbe]

This is firing for me locally when the test fails:

aspnetcore/src/Middleware/HttpLogging/src/FileLoggerProcessor.cs

Lines 197 to 200 in 405567f

	if (cancellationToken.IsCancellationRequested)
	{
	return;
	}

Which returns before the current message is written. Still digging.

[wtgodbe]

Oh, I think I know what's happening. I wait for the file to exist, then dispose - but that dispose could happen between the file getting created here:

aspnetcore/src/Middleware/HttpLogging/src/FileLoggerProcessor.cs

Line 184 in 405567f

var fileInfo = new FileInfo(fullName);

And the CancellationToken check here, which is before the content gets written:

aspnetcore/src/Middleware/HttpLogging/src/FileLoggerProcessor.cs

Line 197 in 405567f

if (cancellationToken.IsCancellationRequested)

So I should really be waiting for the file to exist & have content, rather than just waiting for it to exist. I'll update the tests then do another batched run locally to confirm they stop failing.

We've moved this issue to the Backlog milestone. This means that it is not going to be worked on for the coming release. We will reassess the backlog following the current release and consider this item at that time. To learn more about our issue management process and to have better expectation regarding different types of issues you can read our Triage Process.