Spurious 'Unable to read beyond end of stream' in CI while collecting results

[Cyberboss]

https://travis-ci.org/tgstation/tgstation-server/jobs/438449753#L1156

Not sure what causes this it rarely happens and seemingly at random. Latest coverlet.console

[p10tyr]

Could it be that the files are cleaned up before Coverlet finishes doing its thing.

That error usually occurs when the StreamReader opens a file, it has its Length in memory then starts to stream the data... but its either 0, in very rare occasion in processes of being deleted.

For the Length to be more the length of the file is not possible unless it got modified as mentioned.

Because of this "randomness" it seems like a race condition somewhere.

[prime-gram]

I'm also facing this, but consistently, when dealing with a huge number of testcases (~17k), i.e. in our nightly builds (where more complete testing is done).

In regular use cases, I don't see this happening.

My use case:
I'm calling coverlet, in dotnet test (via cake's DotNetCoreTest)

Error Line:
[16:34:51] : [Step 2/3] C:\Users\SVC-SS-BUILDER\.nuget\packages\coverlet.msbuild\2.3.1\build\netstandard2.0\coverlet.msbuild.targets(27,5): error : Unable to read beyond the end of the stream.

More Detailed:

[16:34:51] :     [Step 2/3] Results File: D:\tc_ba2\510a05667bb2cb9a\test\DynamicPricing.Application.Nightly.Tests\TestResults\TestResults.trx
[16:34:51] :     [Step 2/3] 
[16:34:51] :     [Step 2/3] Total tests: 17071. Passed: 17071. Failed: 0. Skipped: 0.
[16:34:51] :     [Step 2/3] Test Run Successful.
[16:34:51] :     [Step 2/3] Test execution time: 26.1204 Minutes
[16:34:51]i:     [Step 2/3] TRX (1s)
[16:34:51] :     [Step 2/3] 
[16:34:51] :     [Step 2/3] Calculating coverage result...
[16:34:51] :     [Step 2/3] C:\Users\SVC-SS-BUILDER\.nuget\packages\coverlet.msbuild\2.3.1\build\netstandard2.0\coverlet.msbuild.targets(27,5): error : Unable to read beyond the end of the stream. [D:\tc_ba2\510a05667bb2cb9a\test\DynamicPricing.Application.Nightly.Tests\DynamicPricing.Application.Nightly.Tests.csproj]
[16:34:51]E:     [Step 2/3] An error occurred when executing task 'RunTests'.
[16:34:52]E:     [Step 2/3] Error message is logged
[16:34:51]E:     [Step 2/3] Error: System.AggregateException: One or more errors occurred. ---> Cake.Core.CakeException: .NET Core CLI: Process returned an error (exit code 1).
[16:34:51]E:     [Step 2/3]    at Cake.Core.Tooling.Tool`1.ProcessExitCode(Int32 exitCode)
[16:34:51]E:     [Step 2/3]    at Cake.Core.Tooling.Tool`1.Run(TSettings settings, ProcessArgumentBuilder arguments, ProcessSettings processSettings, Action`1 postAction)
[16:34:51]E:     [Step 2/3]    at Cake.Common.Tools.DotNetCore.Test.DotNetCoreTester.Test(String project, DotNetCoreTestSettings settings)
[16:34:51]E:     [Step 2/3]    at Submission#0.DotNetCoreTest(String project, DotNetCoreTestSettings settings)
[16:34:51]E:     [Step 2/3]    at Submission#0.<<Initialize>>b__0_27(String configuration, String provider, Tuple`2 connectionInfo, Boolean nightly, Boolean coverage)
[16:34:51]E:     [Step 2/3]    at Submission#0.<<Initialize>>b__0_26()

[p10tyr]

Yea it looks like coverlet is trying to open the file.. and its not there any more.
Again the common thing here is a CI pipeline.
Can you run this locally on your machine using dotnet test with coverlet?

[prime-gram]

I ran it locally, but was unable to recreate the situation.

In the CI, it did happen always. But not on my laptop.

[p10tyr]

So as I thought it is a CI related issue. Its not the build or coverlet problem it is that CI starts to cleanup too quickly.
Please tell us more about how your CI is setup, which platform etc.

The next step of problem elimination is to manually run it on the CI Agent.

If it is AzureDevops you should be able to get console access to your build agent (i am not sure about self hosted agents though) and try and run the pipeline commands manually. See if it breaks the same way. If it does that means its an environment problem but I seriously doubt that.

To Consider:

I think when the pipeline is executing one after the other.. there is a cleanup operation that is happening. Please check for any options like that and try and do cleanup at the end.. or, on first step do a clean sources and then make sure there are no other cleanup options tagged

Let us know what you find please.

[prime-gram]

That is still not clear to me.

19k Total Tests = (17k nightly + 2k regular baseline)

We in fact have 19k tests, therefore, the 17k tests I was able to run (until I got the exception), was in the middle of the process. Therefore, before a possible CI cleanup (which I'm not sure we do at the end, I believe we cleanup the stuff at the beggining of a CI run).

Another hint: I had the exclusion lists not working properly (I was sending separate exclusion lists, via the command line, and that doesn't work well in powershell, there's an issue for that), which was causing that the extra 17k tests were also being "covered" by coverlet, generating a massive output (my guess, since I'm unable to see the result, because of the exception).

Cheers

[p10tyr]

Yea... I am not entirely sure. The best thing to try and do is recreate the problem somewhere, outside of CI.
Sorry that is all I can say for this

[Cyberboss]

A potential workaround is to invoke bash and sync after

i.e.

$HOME/.dotnet/tools/coverlet bin/$CONFIG/netcoreapp2.1/Tgstation.Server.Api.Tests.dll --target "bash" --targetargs "-c \"dotnet test -c $CONFIG --no-build && sync\"" --format opencover --output "../../TestResults/api.xml" --include "[Tgstation.Server*]*" --exclude "[Tgstation.Server.Api.Tests*]*"

[Cyberboss]

Disregard, it still errored out

[prime-gram]

I have the "feeling" that this has to do with some async (write) operation of some results, and when coverlet tries to read the output of it (it has not finished yet).

but this is just a guess...

[leppie]

Getting this too on AppVeyor lately (last 2 days). Nothing has changed on our side.

[tonerdo]

Not sure what causes this it rarely happens and seemingly at random. Latest coverlet.console

Out of curiosity is everyone having this problem using coverlet.console?

[Cyberboss]

That is what I'm using

…

On Tue, Oct 30, 2018, 10:41 PM Toni Solarin-Sodara ***@***.***> wrote: Not sure what causes this it rarely happens and seemingly at random. Latest coverlet.console Out of curiosity is everyone having this problem using coverlet.console? — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#210 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHywenVul7IKf64aTZG5mVliZtFBZoQZks5uqQ3bgaJpZM4XNyyv> .

[leppie]

Not sure what causes this it rarely happens and seemingly at random. Latest coverlet.console

Out of curiosity is everyone having this problem using coverlet.console?

I am using coverlet.msbuild and just calling dotnet test /p:CollectCoverage=true on a per project basis in AppVeyor.

Still on 2.3.0 here

[prime-gram]

" just calling dotnet test /p:CollectCoverage=true on a per project basis"

Same here. Env: Windows + Teamcity + cake build script (which calls that, then).