16

What may be the reason of my process hanging while waiting for exit?

This code has to start powershell script which inside performs many action e.g start recompiling code via MSBuild, but probably the problem is that it generates too much output and this code gets stuck while waiting to exit even after power shell script executed correctly

it's kinda "weird" because sometimes this code works fine and sometimes it just gets stuck.

Code hangs at:

process.WaitForExit(ProcessTimeOutMiliseconds);

Powershell script executes in like 1-2sec meanwhile timeout is 19sec.

public static (bool Success, string Logs) ExecuteScript(string path, int ProcessTimeOutMiliseconds, params string[] args)
{
    StringBuilder output = new StringBuilder();
    StringBuilder error = new StringBuilder();

    using (var outputWaitHandle = new AutoResetEvent(false))
    using (var errorWaitHandle = new AutoResetEvent(false))
    {
        try
        {
            using (var process = new Process())
            {
                process.StartInfo = new ProcessStartInfo
                {
                    WindowStyle = ProcessWindowStyle.Hidden,
                    FileName = "powershell.exe",
                    RedirectStandardOutput = true,
                    RedirectStandardError = true,
                    UseShellExecute = false,
                    Arguments = $"-ExecutionPolicy Bypass -File \"{path}\"",
                    WorkingDirectory = Path.GetDirectoryName(path)
                };

                if (args.Length > 0)
                {
                    var arguments = string.Join(" ", args.Select(x => $"\"{x}\""));
                    process.StartInfo.Arguments += $" {arguments}";
                }

                output.AppendLine($"args:'{process.StartInfo.Arguments}'");

                process.OutputDataReceived += (sender, e) =>
                {
                    if (e.Data == null)
                    {
                        outputWaitHandle.Set();
                    }
                    else
                    {
                        output.AppendLine(e.Data);
                    }
                };
                process.ErrorDataReceived += (sender, e) =>
                {
                    if (e.Data == null)
                    {
                        errorWaitHandle.Set();
                    }
                    else
                    {
                        error.AppendLine(e.Data);
                    }
                };

                process.Start();

                process.BeginOutputReadLine();
                process.BeginErrorReadLine();

                process.WaitForExit(ProcessTimeOutMiliseconds);

                var logs = output + Environment.NewLine + error;

                return process.ExitCode == 0 ? (true, logs) : (false, logs);
            }
        }
        finally
        {
            outputWaitHandle.WaitOne(ProcessTimeOutMiliseconds);
            errorWaitHandle.WaitOne(ProcessTimeOutMiliseconds);
        }
    }
}

Script:

start-process $args[0] App.csproj -Wait -NoNewWindow

[string]$sourceDirectory  = "\bin\Debug\*"
[int]$count = (dir $sourceDirectory | measure).Count;

If ($count -eq 0)
{
    exit 1;
}
Else
{
    exit 0;
}

where

$args[0] = "C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\MSBuild\Current\Bin\MSBuild.exe"

Edit

To @ingen's solution I added small wrapper which retries to execute hanged up MS Build

public static void ExecuteScriptRx(string path, int processTimeOutMilliseconds, out string logs, out bool success, params string[] args)
{
    var current = 0;
    int attempts_count = 5;
    bool _local_success = false;
    string _local_logs = "";

    while (attempts_count > 0 && _local_success == false)
    {
        Console.WriteLine($"Attempt: {++current}");
        InternalExecuteScript(path, processTimeOutMilliseconds, out _local_logs, out _local_success, args);
        attempts_count--;
    }

    success = _local_success;
    logs = _local_logs;
}

Where InternalExecuteScript is ingen's code

Joelty
  • 1,751
  • 5
  • 22
  • 64
  • at which line actually process hangs ? and intro your code much more – A Farmanbar Feb 17 '20 at 09:20
  • @Mr.AF you're right - done. – Joelty Feb 17 '20 at 09:35
  • Although i think you already checked this thread you will most likely be finding your solution [here](https://stackoverflow.com/questions/139593/processstartinfo-hanging-on-waitforexit-why),one of the possible solutions i read there is to use the WaitForExit() overload that takes no parameter to ensure that asynchronous event handling has been completed.Have you tried that or using the synchronous method to check if it still occurs? – KiKoS Feb 17 '20 at 10:14
  • 1
    The actual calling of Powershell is one thing, however what you are NOT providing is the actual rest of the script you are trying to process while WITHIN Powershell. Calling powershell itself is not the problem, but within what you are trying to do. Edit your post and put the explicit call/commands you are trying to execute. – DRapp Feb 17 '20 at 10:38
  • @KiKoS shouldn't it time out anyway if asynchronous event aren't completed ? – GaspardF Feb 17 '20 at 11:16
  • Are you sure the process you spawn actually terminates? – Lasse V. Karlsen Feb 17 '20 at 11:18
  • What is value of ProcessTimeOutMiliseconds? becuase it Instructs the Process component to wait the specified number of milliseconds for the associated process to exit. – Harshad Vekariya Feb 17 '20 at 11:23
  • @LasseV.Karlsen When this problem happens - process appears in task manager, then after 2-3sec disappears (its fine), then it waits for timeout and then exception is thrown `System.InvalidOperationException: Process must exit before requested information can be determined.` @HarshadVekariya `19000` – Joelty Feb 17 '20 at 11:24
  • that's the reason may be, it will wait for 19000 millisecond probably to exit associated process. can you update that time to very less and check? – Harshad Vekariya Feb 17 '20 at 11:25
  • This may help: https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit?view=netframework-4.8 – Harshad Vekariya Feb 17 '20 at 11:29
  • Are you sure your script didn't tries to (re)build the program itself, which starts it? That may be a possible reason to hand, 'cause exe file is open, so msbuild fails to overwrite it. – lilo0 Feb 17 '20 at 12:22
  • @lilo0 well, no, it recompiles other projects and copies bin content to other disk, it works fine when it works e.g I run my "script executor" 4 times - twice it failed (stuck and then exception after timeout) and other two times it managed to do it fine. – Joelty Feb 17 '20 at 12:28
  • The behavior of this program will be ranked as "highly suspicious" by any half-decent security software. Temporarily disable the installed anti-malware product and try again. – Hans Passant Feb 17 '20 at 14:25
  • @HansPassant the environment where I test it does not use AV – Joelty Feb 17 '20 at 14:30
  • 1
    It's really weird i tried replicating the error. It happened randomly twice on 20 attempts or something and i'm unable to trigger it again. – KiKoS Feb 17 '20 at 15:23
  • @KiKoS hmm - try removing your files (bin,obj,generated exe/dlls and stuff) and recompile it again and try again. I'm not sure whether it will help, but that's how I test it often and at least you managed to reproduce it twice :-) – Joelty Feb 17 '20 at 16:25
  • I've seen problems like this in the past caused by the standard output pipe from the child process being full, because the parent process wasn't reading from it; the child blocks on writing to the pipe, the parent blocks waiting for the child to quit. Deadlock. What I don't understand here is how that would happen if you have event handlers on both pipes from the child; maybe there's a bug with how those pipes are serviced from the threadpool? As a workaround, consider creating threads to read form the child's stdout and stderr. – antiduh Feb 19 '20 at 15:29
  • Can you provide a memory dump of the stuck msbuild process? That could help to rule out other issues. – Alois Kraus Feb 22 '20 at 19:22
  • MSBuild waits 10s for each project to build if the output is locked. When your target compiles in 2-3s and it is then locked then you would wait ca 13s. Your 19s timeout indicates that you have at least two projects where one can be sometimes locked? The code to read from stdout looks fine. – Alois Kraus Feb 23 '20 at 07:58
  • hey @Joelty, curious to know if you've made any break-through yet. – Clint Feb 24 '20 at 12:03
  • @Clint I'm here! I just tested ingen's solution and it works perfectly fine with small wrapper that I added (code's in main post) – Joelty Feb 24 '20 at 14:45
  • 1
    @Joelty, ohh cool interesting, are you saying that `Rx` approach worked (as in it did not timeout) even with stray MSBuild process lying around leading to indefinite wait ? interested to know how that was handled – Clint Feb 24 '20 at 15:19
  • @Clint I just tested twice your approach with `"-nr:False","-m:3"` and it seems to have fixed MSBuild hangs meanwhile there's still `Rx` to "fix" and retry it :) – Joelty Feb 24 '20 at 15:21

4 Answers4

14

Let's start with a recap of the accepted answer in a related post.

The problem is that if you redirect StandardOutput and/or StandardError the internal buffer can become full. Whatever order you use, there can be a problem:

  • If you wait for the process to exit before reading StandardOutput the process can block trying to write to it, so the process never ends.
  • If you read from StandardOutput using ReadToEnd then your process can block if the process never closes StandardOutput (for example if it never terminates, or if it is blocked writing to StandardError).

Even the accepted answer, however, struggles with the order of execution in certain cases.

EDIT: See answers below for how avoid an ObjectDisposedException if the timeout occurs.

It's in these kind of situations, where you want to orchestrate several events, that Rx really shines.

Note the .NET implementation of Rx is available as the System.Reactive NuGet package.

Let's dive in to see how Rx facilitates working with events.

// Subscribe to OutputData
Observable.FromEventPattern<DataReceivedEventArgs>(process, nameof(Process.OutputDataReceived))
    .Subscribe(
        eventPattern => output.AppendLine(eventPattern.EventArgs.Data),
        exception => error.AppendLine(exception.Message)
    ).DisposeWith(disposables);

FromEventPattern allows us to map distinct occurrences of an event to a unified stream (aka observable). This allows us to handle the events in a pipeline (with LINQ-like semantics). The Subscribe overload used here is provided with an Action<EventPattern<...>> and an Action<Exception>. Whenever the observed event is raised, its sender and args will be wrapped by EventPattern and pushed through the Action<EventPattern<...>>. When an exception is raised in the pipeline, Action<Exception> is used.

One of the drawbacks of the Event pattern, clearly illustrated in this use case (and by all the workarounds in the referenced post), is that it's not apparent when / where to unsubscribe the event handlers.

With Rx we get back an IDisposable when we make a subscription. When we dispose of it, we effectively end the subscription. With the addition of the DisposeWith extension method (borrowed from RxUI), we can add multiple IDisposables to a CompositeDisposable (named disposables in the code samples). When we're all done, we can end all subscriptions with one call to disposables.Dispose().

To be sure, there's nothing we can do with Rx, that we wouldn't be able to do with vanilla .NET. The resulting code is just a lot easier to reason about, once you've adapted to the functional way of thinking.

public static void ExecuteScriptRx(string path, int processTimeOutMilliseconds, out string logs, out bool success, params string[] args)
{
    StringBuilder output = new StringBuilder();
    StringBuilder error = new StringBuilder();

    using (var process = new Process())
    using (var disposables = new CompositeDisposable())
    {
        process.StartInfo = new ProcessStartInfo
        {
            WindowStyle = ProcessWindowStyle.Hidden,
            FileName = "powershell.exe",
            RedirectStandardOutput = true,
            RedirectStandardError = true,
            UseShellExecute = false,
            Arguments = $"-ExecutionPolicy Bypass -File \"{path}\"",
            WorkingDirectory = Path.GetDirectoryName(path)
        };

        if (args.Length > 0)
        {
            var arguments = string.Join(" ", args.Select(x => $"\"{x}\""));
            process.StartInfo.Arguments += $" {arguments}";
        }

        output.AppendLine($"args:'{process.StartInfo.Arguments}'");

        // Raise the Process.Exited event when the process terminates.
        process.EnableRaisingEvents = true;

        // Subscribe to OutputData
        Observable.FromEventPattern<DataReceivedEventArgs>(process, nameof(Process.OutputDataReceived))
            .Subscribe(
                eventPattern => output.AppendLine(eventPattern.EventArgs.Data),
                exception => error.AppendLine(exception.Message)
            ).DisposeWith(disposables);

        // Subscribe to ErrorData
        Observable.FromEventPattern<DataReceivedEventArgs>(process, nameof(Process.ErrorDataReceived))
            .Subscribe(
                eventPattern => error.AppendLine(eventPattern.EventArgs.Data),
                exception => error.AppendLine(exception.Message)
            ).DisposeWith(disposables);

        var processExited =
            // Observable will tick when the process has gracefully exited.
            Observable.FromEventPattern<EventArgs>(process, nameof(Process.Exited))
                // First two lines to tick true when the process has gracefully exited and false when it has timed out.
                .Select(_ => true)
                .Timeout(TimeSpan.FromMilliseconds(processTimeOutMilliseconds), Observable.Return(false))
                // Force termination when the process timed out
                .Do(exitedSuccessfully => { if (!exitedSuccessfully) { try { process.Kill(); } catch {} } } );

        // Subscribe to the Process.Exited event.
        processExited
            .Subscribe()
            .DisposeWith(disposables);

        // Start process(ing)
        process.Start();

        process.BeginOutputReadLine();
        process.BeginErrorReadLine();

        // Wait for the process to terminate (gracefully or forced)
        processExited.Take(1).Wait();

        logs = output + Environment.NewLine + error;
        success = process.ExitCode == 0;
    }
}

We already discussed the first part, where we map our events to observables, so we can jump straight to the meaty part. Here we assign our observable to the processExited variable, because we want to use it more than once.

First, when we activate it, by calling Subscribe. And later on when we want to 'await' its first value.

var processExited =
    // Observable will tick when the process has gracefully exited.
    Observable.FromEventPattern<EventArgs>(process, nameof(Process.Exited))
        // First two lines to tick true when the process has gracefully exited and false when it has timed out.
        .Select(_ => true)
        .Timeout(TimeSpan.FromMilliseconds(processTimeOutMilliseconds), Observable.Return(false))
        // Force termination when the process timed out
        .Do(exitedSuccessfully => { if (!exitedSuccessfully) { try { process.Kill(); } catch {} } } );

// Subscribe to the Process.Exited event.
processExited
    .Subscribe()
    .DisposeWith(disposables);

// Start process(ing)
...

// Wait for the process to terminate (gracefully or forced)
processExited.Take(1).Wait();

One of the problems with OP is that it assumes process.WaitForExit(processTimeOutMiliseconds) will terminate the process when it times out. From MSDN:

Instructs the Process component to wait the specified number of milliseconds for the associated process to exit.

Instead, when it times out, it merely returns control to the current thread (i.e. it stops blocking). You need to manually force termination when the process times out. To know when time out has occurred, we can map the Process.Exited event to a processExited observable for processing. This way we can prepare the input for the Do operator.

The code is pretty self-explanatory. If exitedSuccessfully the process will have terminated gracefully. If not exitedSuccessfully, termination will need to be forced. Note that process.Kill() is executed asynchronously, ref remarks. However, calling process.WaitForExit() right after will open up the possibility for deadlocks again. So even in the case of forced termination, it's better to let all disposables be cleaned up when the using scope ends, as the output can be considered interrupted / corrupted anyway.

The try catch construct is reserved for the exceptional case (no pun intended) where you've aligned processTimeOutMilliseconds with the actual time needed by the process to complete. In other words, a race condition occurs between the Process.Exited event and the timer. The possibility of this happening is again magnified by the asynchronous nature of process.Kill(). I've encountered it once during testing.


For completeness, the DisposeWith extension method.

/// <summary>
/// Extension methods associated with the IDisposable interface.
/// </summary>
public static class DisposableExtensions
{
    /// <summary>
    /// Ensures the provided disposable is disposed with the specified <see cref="CompositeDisposable"/>.
    /// </summary>
    public static T DisposeWith<T>(this T item, CompositeDisposable compositeDisposable)
        where T : IDisposable
    {
        if (compositeDisposable == null)
        {
            throw new ArgumentNullException(nameof(compositeDisposable));
        }

        compositeDisposable.Add(item);
        return item;
    }
}
ingen
  • 1,189
  • 5
  • 5
  • 4
    IMHO, definitely worth the bounty. Nice answer, and nice on-topic intro to RX. – quetzalcoatl Feb 22 '20 at 19:20
  • Thanks!!! Your `ExecuteScriptRx` handles `hangs` perfectly. Unfortunely hangs still happen, but I just added small wrapper over your `ExecuteScriptRx` that performs `Retry` and then it it executes fine. Reason of MSBUILD hangs may be @Clint answer. PS: That code made me feel stupid That's first time I see `System.Reactive.Linq;` – Joelty Feb 24 '20 at 14:36
4

The problem is that if you redirect StandardOutput and/or StandardError the internal buffer can become full.

To solve the issues aforementioned you can run the process in separate threads. I do not use WaitForExit, I utilize the process exited event which will return the ExitCode of the process asynchronously ensuring it has completed.

public async Task<int> RunProcessAsync(params string[] args)
    {
        try
        {
            var tcs = new TaskCompletionSource<int>();

            var process = new Process
            {
                StartInfo = {
                    FileName = 'file path',
                    RedirectStandardOutput = true,
                    RedirectStandardError = true,
                    Arguments = "shell command",
                    UseShellExecute = false,
                    CreateNoWindow = true
                },
                EnableRaisingEvents = true
            };


            process.Exited += (sender, args) =>
            {
                tcs.SetResult(process.ExitCode);
                process.Dispose();
            };

            process.Start();
            // Use asynchronous read operations on at least one of the streams.
            // Reading both streams synchronously would generate another deadlock.
            process.BeginOutputReadLine();
            string tmpErrorOut = await process.StandardError.ReadToEndAsync();
            //process.WaitForExit();


            return await tcs.Task;
        }
        catch (Exception ee) {
            Console.WriteLine(ee.Message);
        }
        return -1;
    }

The above code is battle tested calling FFMPEG.exe with command line arguments. I was converting mp4 files to mp3 files and doing over 1000 videos at a time without failing. Unfortunately I do not have direct power shell experience but hope this helps.

Alex
  • 206
  • 2
  • 10
  • It's weird this code, **similarly to other solutions failed (stuck) on FIRST** attempt and then seemed to working fine (like other 5 attempts, I will test it more). Btw why do you perform `BegingOutputReadline` and then perform `ReadToEndAsync` on `StandardError`? – Joelty Feb 20 '20 at 10:25
  • OP is already reading asynchronously, so it's unlikely that a deadlock on the console buffer is the issue here. – yaakov Feb 20 '20 at 11:12
3

For the benefit of readers I'm going to divide this to 2 Sections

Section A: Problem & how to handle similar scenarios

Section B: Problem recreation & Solution

Section A: Problem

When this problem happens - process appears in task manager, then after 2-3sec disappears (its fine), then it waits for timeout and then exception is thrown System.InvalidOperationException: Process must exit before requested information can be determined.

& See Scenario 4 below

In your code:

  1. Process.WaitForExit(ProcessTimeOutMiliseconds); With this you're waiting for Process to Timeout or Exit, which ever takes place first.
  2. OutputWaitHandle.WaitOne(ProcessTimeOutMiliseconds)anderrorWaitHandle.WaitOne(ProcessTimeOutMiliseconds); With this you're waiting for OutputData & ErrorData stream read operation to signal its complete
  3. Process.ExitCode == 0 Gets status of process when it exited

Different settings & their caveats:

  • Scenario 1 (Happy Path): Process completes before the timeout, and thus your stdoutput and stderror also finishes before it and all is well.
  • Scenario 2: Process, OutputWaitHandle & ErrorWaitHandle timesout however stdoutput & stderror is still being read and completes after time out WaitHandlers. This leads to another exception ObjectDisposedException()
  • Scenario 3: Process times-out first (19 sec) but stdout and stderror is in action, you wait for WaitHandler's to times out (19 sec), causing a added delay of + 19sec.
  • Scenario 4: Process times out and code attempts to prematurely query Process.ExitCode resulting in the error System.InvalidOperationException: Process must exit before requested information can be determined.

I have tested this scenario over a dozen times and works fine, following settings have been used while testing

  • Size of Output stream ranging from 5KB to 198KB by initiating build of about 2-15 projects
  • Premature timeouts & process exits within the timeout window


Updated Code

.
.
.
    process.BeginOutputReadLine();
    process.BeginErrorReadLine();

    //First waiting for ReadOperations to Timeout and then check Process to Timeout
    if (!outputWaitHandle.WaitOne(ProcessTimeOutMiliseconds) && !errorWaitHandle.WaitOne(ProcessTimeOutMiliseconds)
        && !process.WaitForExit(ProcessTimeOutMiliseconds)  )
    {
        //To cancel the Read operation if the process is stil reading after the timeout this will prevent ObjectDisposeException
        process.CancelOutputRead();
        process.CancelErrorRead();

        Console.ForegroundColor = ConsoleColor.Red;
        Console.WriteLine("Timed Out");
        Logs = output + Environment.NewLine + error;
       //To release allocated resource for the Process
        process.Close();
        return  (false, logs);
    }

    Console.ForegroundColor = ConsoleColor.Green;
    Console.WriteLine("Completed On Time");
    Logs = output + Environment.NewLine + error;
    ExitCode = process.ExitCode.ToString();
    // Close frees the memory allocated to the exited process
    process.Close();

    //ExitCode now accessible
    return process.ExitCode == 0 ? (true, logs) : (false, logs);
    }
}
finally{}

EDIT:

After hours of playing around with MSBuild I was finally able to reproduce the issue at my system


Section B: Problem Recreation & Solution

MSBuild has -m[:number] switch which is used to specify the maximum number of concurrent processes to use when building.

When this is enabled, MSBuild spawns a number of nodes that lives on even after the Build is complete. Now, Process.WaitForExit(milliseconds) would wait never exit and eventually timeout

I was able to solve this in couple of ways

  • Spawn MSBuild process indirectly through CMD

    $path1 = """C:\Program Files (x86)\Microsoft Visual Studio\2017\Community\MSBuild\15.0\Bin\MSBuild.exe"" ""C:\Users\John\source\repos\Test\Test.sln"" -maxcpucount:3"
    $cmdOutput = cmd.exe /c $path1  '2>&1'
    $cmdOutput
    
  • Continue to use MSBuild but be sure to set the nodeReuse to False

    $filepath = "C:\Program Files (x86)\Microsoft Visual Studio\2017\Community\MSBuild\15.0\Bin\MSBuild.exe"
    $arg1 = "C:\Users\John\source\repos\Test\Test.sln"
    $arg2 = "-m:3"
    $arg3 = "-nr:False"
    
    Start-Process -FilePath $filepath -ArgumentList $arg1,$arg2,$arg3 -Wait -NoNewWindow
    
  • Even If parallel build is not enabled, you could still prevent your process from hanging at WaitForExit by launching the Build via CMD & therefore you do not create a direct dependency on Build process

    $path1 = """C:\....\15.0\Bin\MSBuild.exe"" ""C:\Users\John\source\Test.sln"""
    $cmdOutput = cmd.exe /c $path1  '2>&1'
    $cmdOutput
    

The 2nd approach is preferred since you do not want too many MSBuild nodes to be lying around.

Clint
  • 6,011
  • 1
  • 21
  • 28
  • So, as I said above, thanks, this `"-nr:False","-m:3"` seems to have fixed MSBuild hang-ish behaviour, which with `Rx solution` made whole process somewhat reliable (time's gonna show). I wish I could accept both answers or give two bounties – Joelty Feb 24 '20 at 15:23
  • @Joelty I was just trying to know if `Rx` approach in the other solution able to resolve the issue without applying `-nr:False" ,"-m:3"`. In my understanding it handles indefinite wait from deadlocks and other stuff that I'd covered in section 1. And the rootcause in Section 2 is what I believe is the root cause of the problem that you faced ;) I may be wrong which is why I asked, only time will tell ...Cheers !! – Clint Feb 24 '20 at 16:27
0

Not sure if this is your issue, but looking at MSDN there seems to be some weirdness with the overloaded WaitForExit when you are redirecting output asynchronously. MSDN article recommends calling the WaitForExit that takes no arguments after calling the overloaded method.

Docs page located here. Relevant text:

When standard output has been redirected to asynchronous event handlers, it is possible that output processing will not have completed when this method returns. To ensure that asynchronous event handling has been completed, call the WaitForExit() overload that takes no parameter after receiving a true from this overload. To help ensure that the Exited event is handled correctly in Windows Forms applications, set the SynchronizingObject property.

Code modification might look something like this:

if (process.WaitForExit(ProcessTimeOutMiliseconds))
{
  process.WaitForExit();
}
Tyler Hundley
  • 859
  • 5
  • 11
  • There are some intricacies with the use of `process.WaitForExit()` as indicated by the comments to [this answer](https://stackoverflow.com/a/139604/10246756). – ingen Feb 22 '20 at 19:22