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

Change exit timeout to start ticking on a shutdown request, not at startup #143

Closed
nkolev92 opened this issue Oct 30, 2019 · 4 comments
Closed

Comments

@nkolev92
Copy link
Member

nkolev92 commented Oct 30, 2019

The plugin lifetime in NuGet is managed by idleness.
That means after a certain period of time, NuGet will shutdown the plugin process.

When running in plugin mode, the plugin currently has a 2 min timeout, regardless of what happens.
See:

bool complete = await semaphore.WaitAsync(timeout, cancellationToken).ConfigureAwait(continueOnCapturedContext: false);
if (!complete)
{
logger.Error(Resources.PluginTimedOut);
}

Large solution restores can sometimes last more than 2 minutes. In those cases, the plugin dies and reports an error to NuGet.
NuGet logs that error to stderr.

If NuGet needs the plugin for any other purpose throughout the lifetime of the operation, it will start another plugin process and do that successfully.
So the overall operation succeeds, as far as NuGet is concerned.

It's a common for tooling/CIs to rely on the stderr as a signal of any issues, see:
https://dev.azure.com/dnceng/internal/_build/results?buildId=405076
Windows Build UAP_x86_Release
That fails their whole build operation.

I think the action from the plugin side should be the following:

  1. When in plugin mode, never shutdown the process due to idleness. Allow the nuget counterpart to do that.
    The plugin infrastructure provides a way to monitor the process exit.
  2. Take special care when logging errors that are unrelated to current requests.

//cc @jmyersmsft @dtivel @rrelyea

Note that all of the tests I have done contain 4 NuGet side fixes. If you were to take stock nuget(5.3 and older) + plugin you might not experience this.

Related fixes:

  1. NuGet internally cancelling prematurely. (5.3.1) Plugin: A task was canceled - don't let cancellations affect plugin instantiation NuGet/Home#8648
  2. Logging failures triggering plugin shut down. (5.3.1) Restore Task cannot be safely run twice in one process (when Credential providers are used) NuGet/Home#8688
  3. Propagated exception at dispose time fails the whole auth with a task cancellation error. (5.4) Disposing of a plugin can sometimes throw and fail the whole operation. NuGet/Home#8732
  4. Plugin logging accuracy improvement (5.4) Plugin: Logging time accuracy is off on linux/Mac NuGet/Home#8747

Related issue: NuGet/Home#8528

@jmyersmsft jmyersmsft changed the title The plugin should not log false errors that do not fail any operation Change exit timeout to start ticking on a shutdown request, not at startup Oct 30, 2019
@jmyersmsft
Copy link
Member

I don't think I wrote the offending line originally, so I don't know the original intent, but I think the right behavior is to make it a shutdown timeout, not an overall operation timeout

@nkolev92
Copy link
Member Author

make it a shutdown timeout,

Can you please elaborate?

@jmyersmsft
Copy link
Member

A timeout for the plugin to finish shutting down once a shutdown request has been received

@nkolev92
Copy link
Member Author

nkolev92 commented Nov 5, 2019

@jmyersmsft
The PR didn't autoclose this issue because the fixes part wasn't in the body of the issue.

Closing as it seems like you don't add milestone labels, so it's not necessary to be done from your side.

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

No branches or pull requests

2 participants