Что разрушает мои процессы.StartInfo.OutputDataReceived обратные вызовы преждевременно?

Question

Следующая проблема возникает в .NET Framework версии 3.5. Не знаю, относится ли это к v4 *.

Чтобы захватить stdout для некоторых процессов, я успешно использовал p.StartInfo.UseShellExecute = false; и p.StartInfo.RedirectStandardOutput = true; и обработчик события, подключенный к p.StartInfo.OutputDataReceived+=...;. Затем я звоню p.Start();, затем p.BeginOutputReadLine();, а затем p.WaitForExit();

Все до сих пор. Я получаю все stdout в обработчике событий, как и ожидалось.

Я должен был ввести тайм-аут вместо WaitForExit(), потому что некоторые процессы непредсказуемо запускают запросы для ввода на stdin (например, вы уверены? [Y/n]), ведущие к тупику, где я жду всегда, и так делают.

Первое, что я пробовал, меняется на while (!p.HasExited && DateTime.Now < timeoutmom) p.WaitForExit(200);, где timeoutmoment через 2 минуты после proc.Start(). Это когда я столкнулся с проблемами. Очень последовательно код работает для вызовов, которые производят до нескольких сотен строк stdout, но он ломается для одного вызова, который производит около 7500 строк. Что происходит, то поток proc.WaitForExit(200); выходит из while, когда обработчик события OutputDataReceived был вызван только для ~ 7300 строк (этот номер снова очень согласован, он меняется только на +/- 1 между тестами), и обработчик больше не вызывается для остальных строки stdout, поэтому я их теряю.

Странно, проблема не возникает, если я избегаю WaitForExit(200) и вместо этого использую while (!p.HasExited && DateTime.Now < timeoutmom) System.Threading.Thread.Sleep(1000); (не показано в коде ниже). Когда я разместил вопрос, я был уверен, что проблему удалось избежать, используя Sleep(1000), но я ошибся. Это сработало несколько десятков раз, и тогда этого не произошло, он начал вести себя так же, как когда я проверил WaitForExit(200).

Теперь я предполагаю, что причины этой проблемы: (1) Я занимаю слишком много времени для обработки каждого обратного вызова OutputDataReceived. Я заметил, что проблема усугублялась, когда я добавил условную точку останова в обработчик события, который удлинил выполнение метода множеством. Теперь я могу воспроизвести проблему, просто добавив 3x Debug.WriteLines без условной точки останова; PLUS (2) мой контекст каким-то образом поврежден мной, когда я обратился к HasExited/WaitForExit(200), прежде чем система имела возможность выполнить все обратные вызовы в моем обработчике событий. Теперь я делаю слепой System.Threading.Thread.Sleep(30000) сразу после p.Start() и перед доступом к любому методу p.* и получаю все обратные вызовы. Когда я использовал WaitForExit(), мне показалось, что я могу взять много времени, чтобы обработать каждый обратный вызов, и я все равно получаю их все.

Может ли кто-нибудь почувствовать это?

Код:

private int _execOsProc(
     ProcessStartInfo Psi 
     , string SecInsensArgs 
     , TextWriter ExtraStdOutAndErrTgt 
     , bool OutputToExtraStdOutOnly 
     ) 
    { 
     var pr = new Process(); 
     pr.StartInfo = Psi; 
     pr.StartInfo.UseShellExecute = false; 
     pr.StartInfo.RedirectStandardOutput = pr.StartInfo.RedirectStandardError = true; 
     pr.StartInfo.CreateNoWindow = true; 
     var ol = new DataReceivedEventHandler(this._stdOutDataReceived); 
     var el = new DataReceivedEventHandler(this._stdErrDataReceived); 
     pr.OutputDataReceived += ol; 
     pr.ErrorDataReceived += el; 
     try 
     { 
      __logger.Debug("Executing: \"" + pr.StartInfo.FileName + "\" " + SecInsensArgs); 
      if (ExtraStdOutAndErrTgt == null) 
      { 
       this.__outputToExtraStdOutOnly = false; 
      } 
      else 
      { 
       this.__extraStdOutAndErrTgt = ExtraStdOutAndErrTgt; 
       this.__outputToExtraStdOutOnly = OutputToExtraStdOutOnly; 
      } 
      pr.Start(); 
      pr.BeginOutputReadLine(); 
      pr.BeginErrorReadLine(); 
      var startmom = DateTime.Now; 
      var timeoutmom = startmom.AddMinutes(2); 
      while (!pr.HasExited && DateTime.Now < timeoutmom) pr.WaitForExit(200); 
      pr.CancelOutputRead(); 
      pr.CancelErrorRead(); 
      if (pr.HasExited) 
      { 
       __logger.Debug("Execution finished with exit status code: " + pr.ExitCode); 
       return pr.ExitCode; 
      } 
      else 
      { 
       __logger.Debug("Timeout while waiting for execution to finish"); 
       pr.Kill(); 
       return -100; 
      } 
     } 
     finally 
     { 
      pr.OutputDataReceived -= ol; 
      pr.ErrorDataReceived -= el; 
      if (this.__extraStdOutAndErrTgt != null) 
      { 
       this.__extraStdOutAndErrTgt = null; 
       this.__outputToExtraStdOutOnly = false; 
      } 
     } 
    } 

    private void _stdOutDataReceived(
     object sender 
     , DataReceivedEventArgs e 
     ) 
    { 
     string rdata = string.IsNullOrEmpty(e.Data) ? "" : e.Data.Trim(); 
     if (!this.__outputToExtraStdOutOnly) __logger.Debug("SO: " + rdata); 
     if (this.__extraStdOutAndErrTgt != null) 
     { 
      lock (this.__extraStdOutAndErrTgt) 
      { 
       try 
       { 
        this.__extraStdOutAndErrTgt.WriteLine(rdata); 
        this.__extraStdOutAndErrTgt.Flush(); 
       } 
       catch (Exception exc) 
       { 
        __logger.Warn(
           "WARNING: Error detected but ignored during extra stream write" 
            + " on SODR. Details: " + exc.Message 
           , exc 
           ); 
       } 
      } 
     } 
    } 

    private void _stdErrDataReceived(
     object sender 
     , DataReceivedEventArgs e 
     ) 
    { 
     string rdata = string.IsNullOrEmpty(e.Data) ? "" : e.Data.Trim(); 
     if (!__outputToExtraStdOutOnly) __logger.Debug("SE: " + rdata); 
     if (this.__extraStdOutAndErrTgt != null) 
     { 
      lock (this.__extraStdOutAndErrTgt) 
      { 
       try 
       { 
        this.__extraStdOutAndErrTgt.WriteLine(rdata); 
        this.__extraStdOutAndErrTgt.Flush(); 
       } 
       catch (Exception exc) 
       { 
        __logger.Warn(
           "WARNING: Error detected but ignored during extra stream write" 
            + " on SEDR. Details: " + exc.Message 
           , exc 
           ); 
       } 
      } 
     } 
    } 

Answer 1

Я не уверен, если это решит проблему, но это слишком долго, чтобы разместить его в комментарии.

MSDN говорит о Process.HasExited:

Когда стандартный вывод был перенаправлен на асинхронные события обработчиков, то возможно, что обработка вывода не будет завершена, когда это свойство возвращает истину.Чтобы завершить обработку событий асинхронной обработки , вызовите перегрузку WaitForExit() , которая не принимает параметр перед проверкой HasExited.

и о WaitForExit():

Эта перегрузка гарантирует, что вся обработка завершена, включая обработку асинхронных событий для перенаправлены стандартного вывода. Вы должны использовать эту перегрузку после вызова перегрузки WaitForExit (Int32), когда стандартный вывод был перенаправлен на асинхронные обработчики событий.

Это указывает на то, что вызов WaitForExit() без параметров должны решить эту проблему. Что-то вроде:

var startmom = DateTime.Now; 
var timeoutmom = startmom.AddMinutes(2); 
while (!pr.HasExited && DateTime.Now < timeoutmom) 
    pr.WaitForExit(200); 

if (pr.HasExited) 
{ 
    WaitForExit();//Ensure that redirected output buffers are flushed 

    pr.CancelOutputRead(); 
    pr.CancelErrorRead(); 

    __logger.Debug("Execution finished with exit status code: " + pr.ExitCode); 
    return pr.ExitCode; 
} 
else 
{ 
    pr.CancelOutputRead(); 
    pr.CancelErrorRead(); 

    __logger.Debug("Timeout while waiting for execution to finish"); 

    pr.Kill(); 
    return -100; 
}