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

Avoid throwing an Exception in ToString when a process has already exited #43597

Closed
wants to merge 5 commits into from

Conversation

avodovnik
Copy link

In cases where a process is killed, and ToString is called after that, an exception is thrown. This was due to the use of ProcessName which calls EnsureState - which in turn throws an exception. Instead, we now do a check for the state and fallback to the original base.ToString.

Fixes #1520

@ghost
Copy link

ghost commented Oct 19, 2020

Tagging subscribers to this area: @eiriktsarpalis, @jeffhandley
See info in area-owners.md if you want to be subscribed.

Copy link
Member

@danmoseley danmoseley left a comment

Choose a reason for hiding this comment

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

This seems right. HasExited may end up calling EnsureState(State.Associated), but that does no real work; it may also end up calling UpdateHasExited() and from that point it's pretty hard to reason about whether that might cause a problem, but given the name of the method, it's reasonable to assume it's hardened against the process having exited 😊

@danmoseley
Copy link
Member

@dotnet/runtime-infrastructure possibly transient error in dotnet-install on two OSX legs.

2020-10-19T18:33:27.7004190Z dotnet-install: Downloading link: https://dotnetcli.azureedge.net/dotnet/Sdk/5.0.100-rc.2.20479.15/dotnet-sdk-5.0.100-rc.2.20479.15-osx-x64.tar.gz
2020-10-19T18:33:27.7135770Z curl: (7) Failed to connect to dotnetcli.azureedge.net port 443: Connection refused
2020-10-19T18:33:27.7143010Z dotnet-install: Cannot download: https://dotnetcli.azureedge.net/dotnet/Sdk/5.0.100-rc.2.20479.15/dotnet-sdk-5.0.100-rc.2.20479.15-osx-x64.tar.gz

(curl works for me)

I"ll rerun.

@jaredpar
Copy link
Member

@danmosemsft looks like there is a big spike in SDK install failures in last 24 hours: 49 total across the dotnet org.

https://runfo.azurewebsites.net/search/timelines/?bq=started%3A%7E1&tq=Failed+to+install+dotnet+SDK+from+public+location

@@ -1343,7 +1343,7 @@ private void StopWatchingForExit()

public override string ToString()
{
if (Associated)
if (Associated && !HasExited)
Copy link
Member

Choose a reason for hiding this comment

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

What happens if the process exits after checking HasExited and before accessing ProcessName?

Copy link
Member

Choose a reason for hiding this comment

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

Good point. Catch?

Copy link
Author

Choose a reason for hiding this comment

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

That's a valid question! Is it worth just wrapping this in a try/catch then, or is that unlikely enough to not be a concern?

Copy link
Member

Choose a reason for hiding this comment

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

Where is the problematic exception coming from? i.e. what's the stack of the exception that's thrown if the process has exited?

Copy link
Author

Choose a reason for hiding this comment

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

@stephentoub it's coming from the call to ProcessName which then calls EnsureState ( https://github.com/dotnet/runtime/blob/098fdc5fe634067283369bbb51e7c439431e4105/src/libraries/System.Diagnostics.Process/src/System/Diagnostics/Process.cs#L512) - the state flag it uses means it'll call EnsureState again, this time checking that it has a non-exited process ID (https://github.com/dotnet/runtime/blob/098fdc5fe634067283369bbb51e7c439431e4105/src/libraries/System.Diagnostics.Process/src/System/Diagnostics/Process.cs#L951). That's where the exception gets thrown.

Copy link
Member

Choose a reason for hiding this comment

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

That's where the exception gets thrown.

Hmm, are you sure? It's passing in State.HaveProcessInfo, which doesn't include the bits for HaveNonExitedId, so I would not expect it to be making a call to EnsureState(State.HaveNonExitedId). Rather, I'd expect the exception is coming from here:

_processInfo = ProcessManager.GetProcessInfo(_processId, _machineName);
if (_processInfo == null)
{
throw new InvalidOperationException(SR.NoProcessInfo);
}

with GetProcessInfo returning null and the call then explicitly throwing as a result (the error string thrown also matches the text I see in the exception.

Assuming that's true, then I think I'd prefer to see ToString just rewritten to not use ProcessName at all and avoid the throwing altogether:

public override string ToString()
{
    string result = base.ToString();

    if (Associated)
    {
        _processInfo ??= ProcessManager.GetProcessInfo(_processId, _machineName);
        if (_processInfo is not null)
        {
            string processName = _processInfo.ProcessName;
            if (processName.Length != 0)
            {
                result = $"{result} ({processName})";
            }
        }
    }

    return result;
}

This comment was marked as outdated.

Copy link
Author

Choose a reason for hiding this comment

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

@iSazonov I think, considering I need the base.ToString() in both results, it's fine if I call it in the beginning.

Copy link
Author

Choose a reason for hiding this comment

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

@stephentoub I feel a little bit "bad" setting _processInfo directly from a ToString() method, though. My thinking was the !HasExisted check would be good enough, since it then looks at if ((state & State.HaveProcessInfo) != (State)0). That way the processInfo gets set in the same place you'd expect it to.

Happy to go either way, though.

But yeah, if it exists immediately after that check, maybe it makes sense to do a try/catch.

Copy link
Author

Choose a reason for hiding this comment

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

I've gone ahead with the changes, and rebased while I'm at it.

@adamsitnik adamsitnik added this to the 6.0.0 milestone Oct 20, 2020
In cases where a process is killed, and ToString is called after that,
an exception is thrown. This was due to the use of ProcessName which
calls EnsureState - which in turn throws an exception. Instead, we now
do a check for the state and fallback to the original ToString.

Fix dotnet#1520
@avodovnik avodovnik force-pushed the dev/anvod/tostringfix branch from 098fdc5 to 7857375 Compare November 23, 2020 15:04
@avodovnik avodovnik requested a review from danmoseley November 23, 2020 15:06
[Fact]
public void TestToString_OnExitedProcess()
{
var p = Process.Start("dotnet");
Copy link
Member

@danmoseley danmoseley Nov 23, 2020

Choose a reason for hiding this comment

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

I am not sure we can be certain that "dotnet" is on the path for everyone running this test. I would follow the pattern of other tests, which is to use Process process = CreateProcessLong();. (This just makes a sleeping process) something like

var p = CreateProcessLong();
var name = p.ProcessName;
Assert.Equal($"System.Diagnostics.Process ({name})", p.ToString());
p.Kill();
Assert.Equal("System.Diagnostics.Process", p.ToString());

?

Copy link
Member

Choose a reason for hiding this comment

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

otherwise looks good to me. thanks!

@danmoseley danmoseley closed this Nov 30, 2020
@danmoseley danmoseley reopened this Nov 30, 2020
@danmoseley
Copy link
Member

rerunning CI

@ghost
Copy link

ghost commented Nov 30, 2020

Hello @danmosemsft!

Because this pull request has the auto-merge label, I will be glad to assist with helping to merge this pull request once all check-in policies pass.

p.s. you can customize the way I help with merging this pull request, such as holding this pull request until a specific person approves. Simply @mention me (@msftbot) and give me an instruction to get started! Learn more here.

{
// Handle cases where a process would exit straight after our checks
// and/or make ProcessManager throw an exception.
}
Copy link
Member

Choose a reason for hiding this comment

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

Is this try/catch still needed? What might throw here if the process exits?

Copy link
Author

Choose a reason for hiding this comment

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

@stephentoub ProcessManager.GetProcessInfo can still throw an exception, IIRC - that's why I left the catch block there

@@ -460,6 +460,21 @@ public void TestHasExited()
}
}

[ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))]
public void TestToString_OnExitedProcess()
Copy link
Member

@am11 am11 Jan 7, 2021

Choose a reason for hiding this comment

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

Just curious, does this test fail on master branch? With .NET5, this program:

using System;
using System.Diagnostics;

class Program
{
    static void Main()
    {
        Process p = Process.Start("bash", "-c \"sleep 100000\"");
        Console.WriteLine(p.ProcessName);
        p.Kill();

        Console.WriteLine(p.ToString());
    }
}

displays:

bash
System.Diagnostics.Process (bash)

on Linux and macOS, with return code 0.

Copy link
Author

Choose a reason for hiding this comment

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

@am11 sorry for the delay - yes, the above looks right, in the test we do:

Assert.True(p.WaitForExit(WaitInMS));

In your example, the behaviour is expected, because when you call .ToString() the process is actually still there and the runtime is able to get the information - hence no exception and the information in the output.

Copy link
Member

@am11 am11 Mar 18, 2021

Choose a reason for hiding this comment

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

@avodovnik, ah I missed the WaitForExit. With Process.Start("bash", "--help"); and WaitForExit(10_000), it gives:

Unhandled exception. System.InvalidOperationException: Process has exited, so the requested information is not available.
   at System.Diagnostics.Process.EnsureState(State state)
   at System.Diagnostics.Process.get_ProcessName()

however, with subprocess Process.Start("bash", "-c \"sleep 1\"") and WaitForExit(10_000), it strangely returns subprocess name instead:

sleep
System.Diagnostics.Process (sleep)

(and without WaitForExit, it returns bash in place of sleep as we've seen above)
does this PR change/improve this subprocess behavior?

Copy link
Author

Choose a reason for hiding this comment

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

Yes, the PR follows our own guidelines on not throwing exceptions in ToString and instead falls back to the default value without displaying the process name. As for the sleep case, the returned name is a result of whatever the underlying process manager returns for that PID, and I believe sleep is correct - it is, in fact, the current process running under that id.

@danmoseley
Copy link
Member

Hello @avodovnik have you been able to look at the last comments here? would be great to get this done and merged.

Base automatically changed from master to main March 1, 2021 09:07
@carlossanlop
Copy link
Member

Ping @avodovnik , this has been stale for a couple of months. Any chance you can take a look at the latest feedback?

@avodovnik
Copy link
Author

Ping @avodovnik , this has been stale for a couple of months. Any chance you can take a look at the latest feedback?

Yeah, I will try getting back to it tomorrow or day after!

Copy link
Member

@carlossanlop carlossanlop left a comment

Choose a reason for hiding this comment

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

LGTM as it is.
Thanks for making this change, @avodovnik, and thanks @am11 for your review too.

Copy link
Member

@carlossanlop carlossanlop left a comment

Choose a reason for hiding this comment

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

@avodovnik actually, the CI is old and the results are gone already. Can you please rebase your PR to the latest bits in main so we can ensure the unit tests are passing?

@danmoseley danmoseley closed this Mar 18, 2021
@danmoseley danmoseley reopened this Mar 18, 2021
@danmoseley
Copy link
Member

As far as I know, close/reopen does this for you..

@avodovnik
Copy link
Author

I spent most of this morning trying to figure out if my rebase broke the build or it was already broken in main :D if CI does it automatically, that'd be great, but otherwise I'll see if I can make more progress tomorrow!

@safern
Copy link
Member

safern commented Mar 18, 2021

if CI does it automatically, that'd be great, but otherwise I'll see if I can make more progress tomorrow!

CI should automatically merge with main for PR builds.

Copy link
Member

@carlossanlop carlossanlop left a comment

Choose a reason for hiding this comment

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

@avodovnik the CI finished. The failures are caused by the new unit test, and seems to be affecting all platforms. Some examples:

Libraries Test Run release coreclr Linux x64 Debug

https://helix.dot.net/api/2019-06-17/jobs/a37efb42-7431-49de-8228-55e52170dc95/workitems/System.Diagnostics.Process.Tests/console

Discovering: System.Diagnostics.Process.Tests (method display = ClassAndMethod, method display options = None)
Discovered:  System.Diagnostics.Process.Tests (found 253 of 311 test cases)
Starting:    System.Diagnostics.Process.Tests (parallel test collections = on, max threads = 2)
  System.Diagnostics.Tests.ProcessStartInfoTests.ShellExecute_Nano_Fails_Start [SKIP]
    Condition(s) not met: "IsWindowsNanoServer"
Linux
  System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess [FAIL]
    Assert.Equal() Failure
                                     ↓ (pos 26)
    Expected: ···.Diagnostics.Process
    Actual:   ···.Diagnostics.Process (dotnet)
                                     ↑ (pos 26)
    Stack Trace:
      /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs(477,0): at System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess()
Libraries Test Run release coreclr windows x86 Release

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-43597-merge-0a57a815b1364942a1/System.Diagnostics.Process.Tests/console.db579eca.log?sv=2019-07-07&se=2021-04-07T21%3A51%3A29Z&sr=c&sp=rl&sig=hAYSM1qPcRCeRZJ0XAHLK%2FSjmOlZxnb0BAOA9pRX608%3D

Discovering: System.Diagnostics.Process.Tests (method display = ClassAndMethod, method display options = None)
Discovered:  System.Diagnostics.Process.Tests (found 253 of 277 test cases)
Starting:    System.Diagnostics.Process.Tests (parallel test collections = on, max threads = 2)
  System.Diagnostics.Tests.ProcessStartInfoTests.ShellExecute_Nano_Fails_Start [SKIP]
    Condition(s) not met: "IsWindowsNanoServer"
  System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess [FAIL]
    Assert.Equal() Failure
                                     � (pos 26)
    Expected: úúú.Diagnostics.Process
    Actual:   úúú.Diagnostics.Process (dotnet)
                                     � (pos 26)
    Stack Trace:
      /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs(477,0): at System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess()
Libraries Test Run release mono OSX x64 Debug

https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-43597-merge-f78bf3b5a1d547bea0/System.Diagnostics.Process.Tests/console.84799612.log?sv=2019-07-07&se=2021-04-08T00%3A00%3A39Z&sr=c&sp=rl&sig=QB4lWk99C3%2Fsrc4%2F0o4mGJs72xq0e8kfai8tVkI5mC0%3D

Discovering: System.Diagnostics.Process.Tests (method display = ClassAndMethod, method display options = None)
Discovered:  System.Diagnostics.Process.Tests (found 238 of 311 test cases)
Starting:    System.Diagnostics.Process.Tests (parallel test collections = on, max threads = 12)
  System.Diagnostics.Tests.ProcessStartInfoTests.ShellExecute_Nano_Fails_Start [SKIP]
    Condition(s) not met: "IsWindowsNanoServer"
  System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess [FAIL]
    Assert.Equal() Failure
                                     ↓ (pos 26)
    Expected: ···.Diagnostics.Process
    Actual:   ···.Diagnostics.Process (dotnet)
                                     ↑ (pos 26)
    Stack Trace:
      /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs(477,0): at System.Diagnostics.Tests.ProcessTests.TestToString_OnExitedProcess()
      /_/src/mono/System.Private.CoreLib/src/System/Reflection/RuntimeMethodInfo.cs(378,0): at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
Darwin
  System.Diagnostics.Tests.ProcessTests.TestProcessRecycledPid [SKIP]
    Condition(s) not met: "IsStressModeEnabledAndRemoteExecutorSupported"
  System.Diagnostics.Tests.ProcessTests.CanBeFinalized [SKIP]
    Condition(s) not met: "IsPreciseGcSupported"
Finished:    System.Diagnostics.Process.Tests

@jeffhandley
Copy link
Member

The failures are caused by the new unit test, and seems to be affecting all platforms.

@avodovnik Let us know if you need any help debugging the test failures. Thanks!

@jeffhandley
Copy link
Member

@avodovnik There is now a merge conflict too. I'm going to mark this PR as a Draft for the time-being, but please let us know if you want some help getting this over the finish line. Thanks!

@jeffhandley jeffhandley marked this pull request as draft May 9, 2021 05:22
@ghost ghost closed this Jun 8, 2021
@ghost
Copy link

ghost commented Jun 8, 2021

Draft Pull Request was automatically closed for inactivity. Please let us know if you'd like to reopen it.

@ghost ghost locked as resolved and limited conversation to collaborators Jul 8, 2021
This pull request was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Process.ToString() can throw