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

Use the real submission ID in BuildEventContext. #4048

Merged
merged 1 commit into from
Jan 14, 2019

Conversation

KirillOsenkov
Copy link
Member

Fix #4044. The symptom of the issue is that design-time build logs (such as those obtained from Project System Tools) do not have evaluation messages or imported projects/targets. This is because the MuxLogger used by Microsoft.VisualStudio.ProjectServices.dll drops all build messages where the submission ID is not equal to the current submission ID of the logger. All evaluation messages had the submission ID set to -1 and they were all dropped.

To fix this we need to propagate the submission Id from the build request so that all log events (including evaluation messages) have a proper submission Id set. The way it is right now the BuildEventContext is Invalid, so the Submission ID is set to -1.

With this change the Submission ID is set correctly and I've verified that the evaluation messages are not being discarded by the MuxLogger.

Fix dotnet#4044. The symptom of the issue is that design-time build logs (such as those obtained from Project System Tools) do not have evaluation messages or imported projects/targets. This is because the MuxLogger used by Microsoft.VisualStudio.ProjectServices.dll drops all build messages where the submission ID is not equal to the current submission ID of the logger. All evaluation messages had the submission ID set to -1 and they were all dropped.

To fix this we need to propagate the submission Id from the build request so that all log events (including evaluation messages) have a proper submission Id set. The way it is right now the BuildEventContext is Invalid, so the Submission ID is set to -1.

With this change the Submission ID is set correctly and I've verified that the evaluation messages are not being discarded by the MuxLogger.
@KirillOsenkov
Copy link
Member Author

FYI @panopticoncentral

@@ -1174,7 +1174,7 @@ private ProjectInstance LoadProjectFromFile()
_componentHost.BuildParameters,
_nodeLoggingContext.LoggingService,
new BuildEventContext(
_requestEntry.Request.BuildEventContext.SubmissionId,
_requestEntry.Request.SubmissionId,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is it correct for _requestEntry.Request.BuildEventContext.SubmissionId to be invalid but _requestEntry.Request.SubmissionId valid? If both should be valid, then maybe it's worth fixing that.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've thought about that. The trouble is that BuildEventContext gets reset a few times on the way there, for instance here: https://source.dot.net/#Microsoft.Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs,1094
or here:
https://source.dot.net/#Microsoft.Build/BackEnd/Shared/BuildRequest.cs,132

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In fact this constructor is a direct counterexample to your hypothesis that they should be in sync: it has a submission ID but invalid build event context:
https://source.dot.net/#Microsoft.Build/BackEnd/Shared/BuildRequest.cs,132

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, from your link, it seems that the RequestBuilder is the one that gives the BuildRequest a valid BuildEventContext: https://source.dot.net/#Microsoft.Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs,1094. So during a build, there's a valid submission ID, but not during the evaluation. The evaluation events don't get the submission ID because the submission ID along with the valid BuildEventContext get generated at line 1081 whereas the evaluation happens before that, at line 1063.

So I'd say your fix is fine, with the observation that if future evaluation events would access other BuildEventContext IDs generated at line 1081 in the RequestBuilder, then this fix will have to be changed again.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Alternatively, the fix to fix all bugs of this type would be to separate the generation of submission ID from the logging of ProjectStarted events, so that the evaluation ca use the valid BuildEventContext.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You're right, it's a bit of a chicken and egg. You need the BuildEventContext from ProjectLoggingContext, but that is created later.

@KirillOsenkov
Copy link
Member Author

@livarcocc let's take this?

@livarcocc livarcocc added this to the MSBuild 16.0 milestone Jan 12, 2019
Copy link
Contributor

@livarcocc livarcocc left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@rainersigwald you want to take a look?

@rainersigwald rainersigwald merged commit 08690d6 into dotnet:master Jan 14, 2019
@KirillOsenkov KirillOsenkov deleted the dev-kirillo-submissionid branch January 14, 2019 19:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

MuxLogger drops evaluation events
4 participants