Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

dotnet (6.0.300) restore --verbosity Diagnostic causes MSB0001: Internal MSBuild Error #7622

Closed
narasamdya opened this issue May 13, 2022 · 4 comments · Fixed by #7666
Closed
Assignees
Labels
needs-triage Have yet to determine what bucket this goes in. Partner request regression

Comments

@narasamdya
Copy link

We upgrade the sdk to 6.0.300, and when we ran dotnet restore --verbosity Diagnostic, we got the following error:

dotnet restore --interactive --verbosity Diagnostic
Some command line switches were read from the auto-response file "MSBuild.rsp". To disable this file, use the "-noAutoResponse" switch.
/usr/share/dotnet/sdk/6.0.300/MSBuild.dll -nologo -distributedlogger:Microsoft.DotNet.Tools.MSBuild.MSBuildLogger,/usr/share/dotnet/sdk/6.0.300/dotnet.dll*Microsoft.DotNet.Tools.MSBuild.MSBuildForwardingLogger,/usr/share/dotnet/sdk/6.0.300/dotnet.dll -maxcpucount -property:NuGetInteractive=true -target:Restore -verbosity:m -verbosity:diagnostic /ConsoleLoggerParameters:Verbosity=Minimal;Summary;ForceNoAlign /graph /nodeReuse:false /warnaserror:MSB3026 ./AnyBuild.sln
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter. 
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
   at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.MPPerformanceCounter.AddEventFinished(String projectTargetNames, BuildEventContext buildEventContext, DateTime eventTimeStamp)
   at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.StatusEventHandler(Object sender, BuildStatusEventArgs e)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent, Int32 sinkId)
   at Microsoft.Build.BackEnd.Logging.EventRedirectorToSink.Microsoft.Build.Framework.IEventRedirector.ForwardEvent(BuildEventArgs buildEvent)
   at Microsoft.Build.Logging.ConfigurableForwardingLogger.ForwardToCentralLogger(BuildEventArgs e)
   at Microsoft.Build.Logging.ConfigurableForwardingLogger.BuildStatusHandler(Object sender, BuildStatusEventArgs e)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(BuildEventArgs eventArg)
   at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(Object loggingEvent)
   at Microsoft.Build.BackEnd.Logging.LoggingService.LoggingEventProcessor(Object loggingEvent)
--- End of stack trace from previous location ---
   at Microsoft.Build.Execution.BuildManager.EndBuild()
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)

MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter. 
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Execute(String[] commandLine)
Unhandled exception: Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter. 
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Execute(String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Main(String[] args)
   at Microsoft.DotNet.Cli.Utils.MSBuildForwardingAppWithoutLogging.ExecuteInProc(String[] arguments)
@rainersigwald rainersigwald added regression Partner request needs-triage Have yet to determine what bucket this goes in. labels May 13, 2022
@narasamdya
Copy link
Author

To give some context, this is the repository that we build: https://dev.azure.com/mseng/Domino/_git/AnyBuild

@rainersigwald
Copy link
Contributor

I repro on @narasamdya's (MSFT-internal) repo, only on Linux.

It looks like there's a Directory.Build.rsp file in that repo root that specifies /ConsoleLoggerParameters:Verbosity=Minimal;Summary;ForceNoAlign. It looks like the verbosity there is what matters.

With that I can repro in WSL on a template classlib project:

$ dotnet restore --verbosity Diagnostic -flp:v=diag "/ConsoleLoggerParameters:Verbosity=Minimal"
/usr/share/dotnet/sdk/6.0.300/MSBuild.dll -nologo -distributedlogger:Microsoft.DotNet.Tools.MSBuild.MSBuildLogger,/usr/share/dotnet/sdk/6.0.300/dotnet.dll*Microsoft.DotNet.Tools.MSBuild.MSBuildForwardingLogger,/usr/share/dotnet/sdk/6.0.300/dotnet.dll -flp:v=diag -maxcpucount -target:Restore -verbosity:m -verbosity:diagnostic /ConsoleLoggerParameters:Verbosity=Minimal ./TemplateClasslib.csproj
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
   at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.MPPerformanceCounter.AddEventFinished(String projectTargetNames, BuildEventContext buildEventContext, DateTime eventTimeStamp)
   at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.StatusEventHandler(Object sender, BuildStatusEventArgs e)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent, Int32 sinkId)
   at Microsoft.Build.BackEnd.Logging.EventRedirectorToSink.Microsoft.Build.Framework.IEventRedirector.ForwardEvent(BuildEventArgs buildEvent)
   at Microsoft.Build.Logging.ConfigurableForwardingLogger.ForwardToCentralLogger(BuildEventArgs e)
   at Microsoft.Build.Logging.ConfigurableForwardingLogger.BuildStatusHandler(Object sender, BuildStatusEventArgs e)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent)
   at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(BuildEventArgs eventArg)
   at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(Object loggingEvent)
   at Microsoft.Build.BackEnd.Logging.LoggingService.LoggingEventProcessor(Object loggingEvent)
--- End of stack trace from previous location ---
   at Microsoft.Build.Execution.BuildManager.EndBuild()
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)

MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Execute(String[] commandLine)
Unhandled exception: Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Execute(String[] commandLine)
   at Microsoft.Build.CommandLine.MSBuildApp.Main(String[] args)
   at Microsoft.DotNet.Cli.Utils.MSBuildForwardingAppWithoutLogging.ExecuteInProc(String[] arguments)

@robvdnieuw
Copy link

robvdnieuw commented Jun 2, 2022

With Visual Studio 2022 update 17.2.3 installed we get the same error when calling
C:\Program Files\Microsoft Visual Studio\2022\professional\MSBuild\Current\Bin\msbuild.exe /v:diag

When we change to /v:d it works.

it is 100% reproducible at our site.

rainersigwald pushed a commit that referenced this issue Jun 23, 2022
Specifying both diagnostic verbosity and minimal verbosity led to an internal exception on linux because the start/stop events were enabled independently but some codepaths assumed that if one existed the other did too.

Fixes #7622
@chm-tm
Copy link

chm-tm commented Jul 11, 2022

Similar to @robvdnieuw, I have version 17.2.1+52cd2da31 for .NET framework installed and I get a very similar stack trace when using the MSBuild Log Viewer with my project:

C:\Program Files\Microsoft Visual Studio\2022\Professional\MSBuild\Current\Bin\amd64\MSBuild.exe /nologo /bl /clp:NoSummary;Verbosity=minimal /m /v:diag C:\somewhere\MyNet6SdkProject.csproj
MSBUILD : error MSB1025: Interner Fehler beim Ausführen von MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   bei Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
   bei Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.MPPerformanceCounter.AddEventFinished(String projectTargetNames, BuildEventContext buildEventContext, DateTime eventTimeStamp)
   bei Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.StatusEventHandler(Object sender, BuildStatusEventArgs e)
   bei Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   bei Microsoft.Build.Logging.ConfigurableForwardingLogger.BuildStatusHandler(Object sender, BuildStatusEventArgs e)
   bei Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
   bei Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(BuildEventArgs eventArg)
   bei Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(Object loggingEvent)
   bei Microsoft.Build.BackEnd.Logging.LoggingService.LoggingEventProcessor(Object loggingEvent)
--- Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde ---
   bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   bei Microsoft.Build.Execution.BuildManager.EndBuild()
   bei Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Boolean needToValidateProject, String schemaFile, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String commandLine)

MSBUILD : error MSB1025: Interner Fehler beim Ausführen von MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   bei Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Boolean needToValidateProject, String schemaFile, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String commandLine)
   bei Microsoft.Build.CommandLine.MSBuildApp.Execute(String commandLine)

Unbehandelte Ausnahme: Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Cannot have finished counter without started counter.
   bei Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Boolean needToValidateProject, String schemaFile, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String commandLine)
   bei Microsoft.Build.CommandLine.MSBuildApp.Execute(String commandLine)
   bei Microsoft.Build.CommandLine.MSBuildApp.Main()

So I'd glad to see an updated version with one of the next minor VS patches.
So far, I work around the issue by creating the .binlog outside the viewer without passing /clp.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs-triage Have yet to determine what bucket this goes in. Partner request regression
Projects
None yet
5 participants