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

Mount: Remove unnecessary tracing #415

Merged
merged 1 commit into from
Oct 29, 2018
Merged

Conversation

jeschu1
Copy link
Member

@jeschu1 jeschu1 commented Oct 22, 2018

We may fail to attach the filter from GVFS.exe due to the user not running as admin. In this case we will retry the mount via GVFS.Service.exe. We don't want GVFS.exe to log a failure telemetry event, since it may get successfully retried. This change removes the tracing, since the if called via the service we will still log an error here and send it back to GVFS.exe.

If we want to get more precise the error code I see on failing to attach the filter without permissions is (2147942405 or 0x80070005). We could add specific handling for that code if we think that's more appropriate.

@jeschu1 jeschu1 requested review from sanoursa and wilbaker October 22, 2018 20:01
// This code is shared between GVFS.exe and GVFS.Service.exe
// GVFS.exe failures will be retried by GVFS.Service.exe
// Warn the user and allow the caller to determine how to handle the error
tracer.RelatedWarning(errorMessage);
Copy link
Contributor

Choose a reason for hiding this comment

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

Though more to the point, I think we can just drop this line altogether. The callers already log all errors, so this is just duplicating the work. I think that applies to all the tracer calls in this method - I think it's not really this method's business to decide what is an error and what is not.

Copy link
Member Author

Choose a reason for hiding this comment

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

@sanoursa makes sense thanks! I was debating dropping the line, but thinking if we do it for one we'd want to drop them all. Definitely cleaner this way.

@jeschu1 jeschu1 changed the title Warn on Filter Error Remove unnecessary tracing Oct 23, 2018
@jeschu1 jeschu1 changed the title Remove unnecessary tracing Mount: Remove unnecessary tracing Oct 23, 2018
@@ -373,7 +370,7 @@ public bool IsReady(JsonTracer tracer, string enlistmentRoot, out string error)
return
IsServiceRunning(tracer) &&
IsNativeLibInstalled(tracer, new PhysicalFileSystem()) &&
TryAttach(tracer, enlistmentRoot, out error);
TryAttach(enlistmentRoot, out error);
Copy link
Member

Choose a reason for hiding this comment

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

It looks like the error being returned is not being logged by the MountVerb:

if (!GVFSPlatform.Instance.KernelDriver.IsReady(tracer, enlistment.EnlistmentRoot, out errorMessage))
{
    tracer.RelatedInfo($"{nameof(MountVerb)}.{nameof(this.Execute)}: Enabling and attaching ProjFS through service");

    if (!this.ShowStatusWhileRunning(
        () => { return this.TryEnableAndAttachPrjFltThroughService(enlistment.EnlistmentRoot, out errorMessage); },
        $"Attaching ProjFS to volume"))
    {

Could you add this error message here:

    tracer.RelatedInfo($"{nameof(MountVerb)}.{nameof(this.Execute)}: Enabling and attaching ProjFS through service");

So that we can see in the mount verb logs why GVFS decided to ask the service?

Copy link
Member Author

Choose a reason for hiding this comment

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

@wilbaker Let me know what you think of the log message. That sort of thing is not my forte :-).

Copy link
Member

Choose a reason for hiding this comment

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

I think the message sounds good, but I think we can combine these into a single call and use EventMetadata. I'll add a comment by the new code with what I mean.

@@ -117,6 +117,7 @@ protected override void Execute(GVFSEnlistment enlistment)

if (!GVFSPlatform.Instance.KernelDriver.IsReady(tracer, enlistment.EnlistmentRoot, out errorMessage))
{
tracer.RelatedInfo("ProjFs failed to start due to " + errorMessage);
tracer.RelatedInfo($"{nameof(MountVerb)}.{nameof(this.Execute)}: Enabling and attaching ProjFS through service");
Copy link
Member

Choose a reason for hiding this comment

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

You could do a single tracer call here like this:

tracer.RelatedEvent(
    EventLevel.Informational, 
    $"{nameof(MountVerb)}_{nameof(this.Execute)}_EnablingKernelDriverViaService", 
    new EventMetadata
    {
        { "KernelDriver.IsReady_Error", errorMessage }
    });

Copy link
Member

Choose a reason for hiding this comment

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

And if you want to include a message you can just add it to the EventMetadata:

{ TracingConstants.MessageKey.InfoMessage, "Your message here" }

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 added a message for clarity, so the line reads:

[2018-10-25 11:06:47 -04:00] MountVerb_Execute_EnablingKernelDriverViaService {"KernelDriver.IsReady_Error":"Attaching the filter driver resulted in: 2147942405","Message":"Service will retry"}

Copy link
Member

@wilbaker wilbaker left a comment

Choose a reason for hiding this comment

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

Approved with suggestions

Allow the caller to determine how to handle the error.  This is because a command line error may fail due to permissions and be retried successfully by the service.
@jeschu1 jeschu1 merged commit 85c5cb8 into microsoft:master Oct 29, 2018
@jrbriggs jrbriggs added this to the S147 milestone Feb 7, 2019
@jrbriggs jrbriggs added the affects: live-site Improving our ability to diagnose and fix the product label Feb 8, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects: live-site Improving our ability to diagnose and fix the product
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants