Coverage analysis failing due to "Invalid stream header!"

Answered

I'm using Visual Studio Professional 2017 RC3 (26127.3) and ReSharper Ultimate 2016.3.2. Since the installation of VS2017 and upgrading ReSharper I can't run the code coverage of my tests (neither on VS2017 nor on VS2015). 

By running the coverage analysis on a single test class I end up with the following error message: "Coverage analysis: Invalid stream header!". Instead, when I'm trying to cover all test in the solution the process simply does not stop and the UI shows only the message "Coverage analysis is in progress" forever.

Re-opening the solution and rebooting the machine did not help. Any ideas?

14 comments
Comment actions Permalink

I'm seeing the same issue, I've attached the workspace host log.

12:42:35.981 |I| UnitTestSessionManager | HandleAnalysisFinished
12:42:35.982 |I| CoverageSnapshotManager | Merging snapshots 1-4
12:42:36.704 |I| CoverageSnapshotManager | Merge finished
12:42:36.710 |I| UnitTestSessionOperationManager| Operation aborted
12:42:36.710 |I| UnitTestSessionOperationManager| Operation error: Invalid stream header!
12:42:36.710 |I| UnitTestSessionOperationManager| Operation finished
12:42:36.711 |W| | Invalid stream header!

--- EXCEPTION #1/2 [PdbException]
Message = “Invalid stream header!”
ExceptionPath = Root.InnerException
ClassName = JetBrains.Metadata.Utils.Pdb.Common.PdbException
HResult = COR_E_EXCEPTION=80131500
Source = JetBrains.Platform.Metadata
StackTraceString = “
at JetBrains.Metadata.Utils.Pdb.PdbHeader..ctor(BinaryReader reader)
at JetBrains.Metadata.Utils.Pdb.PdbFile..ctor(Stream pdbStream)
at JetBrains.dotCover.DataAccess.SnapshotCore.Dal.Complementer.CoverageSnapshotStorageComplementer.TryGetAssemblyMetadataAndPdb(Lifetime lifetime, FileSystemPath assemblyPath, Stream& metadataStream, PdbFile& pdbFile)
at JetBrains.dotCover.DataAccess.SnapshotCore.Dal.Complementer.CoverageSnapshotStorageComplementer.Complement(ISnapshotStorage sourceStorage, IStorageSectionWriter storageAppender, ISnapshotScopeInfoProvider snapshotScopeInfoProvider, Predicate`1 includeModule, IEnumerable`1 patternFilters, IEnumerable`1 attributeFilters, IProgressIndicator progress)
at JetBrains.dotCover.DataAccess.SnapshotCore.Dal.CoverageSnapshotManager.Complement(IStorageDescriptor source, ISnapshotScopeInfoProvider snapshotScopeInfoProvider, Predicate`1 includeModule, IEnumerable`1 patternFilters, IEnumerable`1 attributeFilters, IProgressIndicator progress)
at JetBrains.dotCover.Workspace.Impl.UnitTesting.Model.UnitTestSessionManager.HandleAnalysisFinished(ProgressId progressId, Boolean complementSnapshot, CoverageFilterSet coverageFilters, AttributeFilterSet attributeFilters, ElementInfoProvider elementInfoProvider)
at SyncInvokeHandleAnalysisFinished(Object , Object[] , Object[] )
at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage11(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)

--- Outer ---

--- EXCEPTION #2/2 [LoggerException]
Message = “Invalid stream header!”
ExceptionPath = Root
ClassName = JetBrains.Util.LoggerException
InnerException = “Exception #1 at Root.InnerException”
HResult = COR_E_APPLICATION=80131600
StackTraceString = “
at System.ServiceModel.Dispatcher.ErrorBehavior.HandleErrorCommon(Exception error, ErrorHandlerFaultInfo& faultInfo)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessageCleanup(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage9(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage8(MessageRpc& rpc)
at System.ServiceModel.Dispatcher.MessageRpc.ProcessError(Exception e)
at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
at System.ServiceModel.Dispatcher.ChannelHandler.DispatchAndReleasePump(RequestContext request, Boolean cleanThread, OperationContext currentOperationContext)
at System.ServiceModel.Dispatcher.ChannelHandler.HandleRequest(RequestContext request, OperationContext currentOperationContext)
at System.ServiceModel.Dispatcher.ChannelHandler.AsyncMessagePump(IAsyncResult result)
at System.ServiceModel.Dispatcher.ChannelHandler.OnAsyncReceiveComplete(IAsyncResult result)
at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
at System.Runtime.AsyncResult.Complete(Boolean completedSynchronously)
at System.ServiceModel.Channels.TransportDuplexSessionChannel.TryReceiveAsyncResult.OnReceive(IAsyncResult result)
at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
at System.Runtime.AsyncResult.Complete(Boolean completedSynchronously)
at System.ServiceModel.Channels.SynchronizedMessageSource.ReceiveAsyncResult.OnReceiveComplete(Object state)
at System.ServiceModel.Channels.SessionConnectionReader.OnAsyncReadComplete(Object state)
at System.ServiceModel.Channels.PipeConnection.OnAsyncReadComplete(Boolean haveResult, Int32 error, Int32 numBytes)
at System.ServiceModel.Channels.OverlappedContext.CompleteCallback(UInt32 error, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)

0
Comment actions Permalink

The same applies in my case, here something more (lines just before the exception posted by Donald Buchanan) from always from the workspace host log:

07:51:59.608 |I| | JetBrains dotCover Workspace Host 2016.3.2. Build 107.0.20170126.121718
07:51:59.612 |I| | LogLevel: INFO
07:51:59.745 |I| Main | Workspace host started.
07:51:59.745 |I| Main | Workspace id: 90f1b744-e938-45f9-b84a-1909ee4aee0b
07:52:00.079 |I| HostsPool | IWorkspacePresentableNameManager service host initialized
07:52:00.080 |I| HostsPool | IWorkspaceSnapshotLocationProvider service host initialized
07:52:00.081 |I| HostsPool | IWorkspaceSnapshotManager service host initialized
07:52:00.081 |I| HostsPool | IWorkspaceSnapshotStateProvider service host initialized
07:52:00.081 |I| HostsPool | IWorkspaceSnapshotPersistenceStateManager service host initialized
07:52:00.082 |I| HostsPool | ISnapshotMerger service host initialized
07:52:00.082 |I| HostsPool | IUnitTestCoverageOptionsManager service host initialized
07:52:00.083 |I| HostsPool | IUnitTestSessionOperationManager service host initialized
07:52:00.085 |I| HostsPool | IUnitTestSessionManagerServer service host initialized
07:52:00.085 |I| HostsPool | IUnitTestSessionSnapshotScopeConfigurator service host initialized
07:52:00.086 |I| HostsPool | IAffectedTestsDetectionService service host initialized
07:52:00.093 |I| HostsPool | IWorkspaceContinuousTestingPersistenceManager service host initialized
07:52:00.095 |I| HostsPool | ICoverageDetailsProvider service host initialized
07:52:00.095 |I| HostsPool | IPerformanceDetailsProvider service host initialized
07:52:00.096 |I| HostsPool | ICoverageFiltersFactory service host initialized
07:52:00.097 |I| HostsPool | ICoverageTreeStructureProvider service host initialized
07:52:00.098 |I| HostsPool | IMetadataBasedCoverageTreeConfigurator service host initialized
07:52:00.099 |I| HostsPool | ISolutionBasedCoverageTreeConfigurator service host initialized
07:52:00.100 |I| HostsPool | IFilterableCoverageTreeConfigurator service host initialized
07:52:00.101 |I| HostsPool | IAutoPropertiesHidingCoverageTreeConfigurator service host initialized
07:52:00.101 |I| HostsPool | IRiskMetricsProvider service host initialized
07:52:00.102 |I| HostsPool | IPathMappingRootConsumer service host initialized
07:52:00.103 |I| HostsPool | IPdbStatementRangesProvider service host initialized
07:52:00.104 |I| HostsPool | IDocumentStatementsCoverageProvider service host initialized
07:52:00.104 |I| HostsPool | IDocumentReverseCoverageProvider service host initialized
07:52:00.105 |I| HostsPool | ICoverageTreeReverseCoverageProvider service host initialized
07:52:00.106 |I| HostsPool | ICoverageNodesSourceCodeInfoProvider service host initialized
07:52:00.107 |I| HostsPool | ISourceCodeToCoverageTreeMapper service host initialized
07:52:00.108 |I| HostsPool | IHtmlReportBuilder service host initialized
07:52:00.108 |I| HostsPool | IJsonReportBuilder service host initialized
07:52:00.109 |I| HostsPool | INDependReportBuilder service host initialized
07:52:00.109 |I| HostsPool | ITeamCityReportBuilder service host initialized
07:52:00.110 |I| HostsPool | IUncoveredLinesReportBuilder service host initialized
07:52:00.110 |I| HostsPool | IXmlReportBuilder service host initialized
07:52:00.111 |I| HostsPool | IDetailedXmlReportBuilder service host initialized
07:52:00.112 |I| HostsPool | IEnvironmentSectionExplorerModel service host initialized
07:52:00.114 |I| HostsPool | IFunctionInfoExplorerModel service host initialized
07:52:00.114 |I| HostsPool | IModuleStatSectionExplorerModel service host initialized
07:52:00.115 |I| HostsPool | IWorkspaceHostShutdowner service host initialized
07:52:00.124 |I| HostsPool | ISignalReceiverRegistrationService service host initialized
07:52:00.125 |I| HostsPool | IProgressService service host initialized
07:52:00.125 |I| HostsPool | IAvailabilityCheckService service host initialized
07:52:00.126 |I| Main | Workspace host initialized in 380 ms
07:52:01.097 |I| UnitTestSessionOperationManager| Starting operation. Type CoverageAnalysis
07:52:03.274 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Juqopuz.tmp'. Transient = False
07:52:03.959 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Duxeqal.tmp'. Transient = False
07:52:05.834 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Dixohib.tmp'. Transient = False
07:52:09.118 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Nygysev.tmp'. Transient = False
07:52:11.584 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Tyduwim.tmp'. Transient = False
07:52:11.601 |I| CoverageSnapshotManager | Merging snapshots 1-5
07:52:14.007 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Pajydyc.tmp'. Transient = False
07:52:16.969 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Fenutej.tmp'. Transient = False
07:52:18.060 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Xagacot.tmp'. Transient = False
07:52:19.195 |I| CoverageSnapshotManager | Merge finished
07:52:24.882 |I| UnitTestSessionManager | HandleSnapshotReceived. IndexFile = 'C:\Users\xxx\AppData\Local\Temp\ssd.Virykaj.tmp'. Transient = False
07:52:24.883 |I| CoverageSnapshotManager | Merging snapshots 1-5
07:52:25.270 |I| UnitTestSessionManager | HandleAnalysisFinished
07:54:07.794 |I| CoverageSnapshotManager | Merge finished
07:54:08.044 |I| UnitTestSessionOperationManager| Operation aborted
07:54:08.045 |I| UnitTestSessionOperationManager| Operation error: Invalid stream header!
07:54:08.045 |I| UnitTestSessionOperationManager| Operation finished
07:54:08.055 |W| | Invalid stream header!
0
Comment actions Permalink

Hello,

The problem consists in that dotCover 2016.3.x doesn't fully support new portable PDB format. As a workaround in 2016.3 you can try one of the following options:

- disable "Include not loaded solution assemblies into coverage results" option (ReSharper >> Options >> dotCover >> General)

- change debug info type for your projects from "portable" to "full"

The issue is fixed in ReSharper 2017.1 EAP. You are welcome to try it: https://www.jetbrains.com/resharper/eap/

Best regards.

1
Comment actions Permalink

Hi,

I've tried to disable the ReSharper option and to install the EAP but both did not work with my solution. I've 74 projects (33 test projects) with ~5000 unit tests and the last time I've managed to run the coverage I had ~96%. It is really disappointing since I really need a way to produce the coverage results to provide this information to the customer. 

The coverage still runs forever and can't be stopped. Moreover, I can't toggle the code highlighting either.

Any ideas? 

0
Comment actions Permalink

Hi Timoty,

Could you please clarify in which version of Visual Studio you have these problems?
ReSharper 2017.1 EAP1 doesn't have full support for. NET Core unit tests in VS2017 RC, it will be included later. 

 

0
Comment actions Permalink

Hi Fedor,

currently I'm using Visual Studio Professional 2017 RC (15.0.0-RC4+26206.0) and ReSharper 2017.1 EAP 1.

I wan't to clarify a few things:

  • there is no .NET core project in the solution. I had a ASP.NET Core one but I converted it to the "old" csproj the first time I opened the solution in VS2017
  • I've actually tried to run the coverage of only one project at a time and it seems to work. However, it takes more than several minutes to compute the coverage percentage and update the UI (the test run is "normal" time, then I've to way 10+ minutes for covering ~50 test or so). Even covering a single test requires <1ms to run and 30sec to compute the coverage
  • The number of projects in the solution does not matter. For testing purposes I've created smaller solutions with ~10 projects (5 code and 5 test) and the effect is the same: test running in regular time, coverage taking way to much to compute

I'm supposing that even running the coverage on the "big" solution with all projects (that before the update took less than 5min to run all tests and compute the solution coverage) may at the end work, but sincerely I can't invest hours of time in waiting and hoping that the coverage process may come to an end.

0
Comment actions Permalink

Hi Timoty,

Yes, that's not expected slowdown. Could you please send us ReSharper log files when covering a single project?

To turn on logging start VS with the following command line arguments:

devenv.exe /ReSharper.LogLevel Verbose /ReSharper.LogFile

Log files will be saved in the '%Temp%\JetLogs' folder with auto-generated names, so empty this folder before you launch VS.

Also, could you clarify from which version of ReSharper have you updated?

0
Comment actions Permalink

Hi Fedor

the upgrade steps were:

  • VS2015 and ReSharper 2016.3.2 --> here the coverage over the solution was OK
  • download of VS2017 RC3
  • update of ReSharper 2016.3.2 to support the new VS2017
  • open the solution in VS2017 (with one ASP.NET Core project with standard Framework being converted to the csproj format)
  • coverage performances KO --> over the entire solution practically unusable

I've cleaned up and rebooted the machine in this days, tried different things but it seems still slow.

I've done a run over a single project with 300 tests (simply opening VS, opening the unit test window, run the coverage over a single project). I've used a stopwatch (so consider some +/-), but the actual coverage took ~10sec and the UI updated after ~1m. Seems not that bad, but I think that the slower results that I had were also influenced on me trying the full solution coverage first. If I try it, all 4890 tests are covered in ~2m (i noticed several exception in the EAP UI popping out) but then after 10m of waiting I've tried to stop the process and eventually killed VS.

Here both full logs:

 

0
Comment actions Permalink

Hi Timoty,

Thank you for the detailed information and log files!
Could you please check the "Run up to N assemblies in parallel" option in ReSharper | Options | Unit Testing | General? What do you have there? If it isn't 1, please try to set it in 1 and then run coverage.

0
Comment actions Permalink

Hi Fedor

I had indeed 3 as setting there. I've tried to set it to 1 and actually it managed to complete the coverage execution of the whole solution. Obviously the running of the test performed way slower than usual but at the end the the coverage was successfully computed.

Is it there a problem with that setting? Will it be somehow tracked and eventually solved (to improve the performances of the test execution)?

 

0
Comment actions Permalink

Yes, unfortunately, there can be a noticeable overhead because of merging of multiple coverage snapshots obtained from different processes in case if the assemblies-level parallelism is enabled. We are working on improvements in the merge mechanism to decrease this overhead.

0
Comment actions Permalink

Hi Fedor,

so for the time being I'll leave this setting to 1 and wait a bit longer for the execution of the tests but at least will obtain for sure a result. Do you have an idea when this problems may be solved? Is there already a tracked issue for this? Just in order to follow it and be up to date with it.

0
Comment actions Permalink

Hi Timoty,

Currently, we don't have any estimates for the fix. I've opened a report in Youtrack: https://youtrack.jetbrains.com/issue/DCVR-8682, you are welcome to track its status.

 

0
Comment actions Permalink

Hi Fedor,

fantastic, thank you.

0

Please sign in to leave a comment.