csi.exe should emit exception to stderr, not stdout

[atifaziz]

On error, csi.exe should dump the exception to STDERR, instead of STDOUT as it does currently, and this PR fixes that.

Try the following on a 64-bit Windows Command Prompt (tested against csi version 1.1.0.51109):

echo throw new Exception("BOOM!");> test.csx && "%ProgramFiles(x86)%\MSBuild\14.0\bin\csi.exe" test.csx 2>log.txt || echo NOK

The normal expectation is that only NOK should be displayed and log.txt contains the exception text. Instead, log.txt is empty and one gets the following output on the console:

System.AggregateException: One or more errors occurred. ---> System.Exception: BOOM!
   at Submission#0.<<Initialize>>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.CodeAnalysis.Scripting.ScriptExecutionState.<RunSubmissionsAsync>d__9`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.CodeAnalysis.Scripting.Script`1.<RunSubmissionsAsync>d__19.MoveNext()
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at Microsoft.CodeAnalysis.Scripting.Hosting.CommandLineRunner.RunScript(ScriptOptions options, String code, ErrorLogger errorLogger, CancellationToken cancellationToken)
   at Microsoft.CodeAnalysis.Scripting.Hosting.CommandLineRunner.RunInteractiveCore(ErrorLogger errorLogger)
   at Microsoft.CodeAnalysis.Scripting.Hosting.CommandLineRunner.RunInteractive()
   at Microsoft.CodeAnalysis.CSharp.Scripting.Hosting.Csi.Main(String[] args)
---> (Inner Exception #0) System.Exception: BOOM!
   at Submission#0.<<Initialize>>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.CodeAnalysis.Scripting.ScriptExecutionState.<RunSubmissionsAsync>d__9`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.CodeAnalysis.Scripting.Script`1.<RunSubmissionsAsync>d__19.MoveNext()<---

NOK

After applying/merging this PR, only NOK should appear on the console and the exception text should end up in log.txt

[jaredpar]

The compiler tools in general though never emit to standard error, always to standard out. Why should CSI be different here?

[atifaziz]

Because that's what good citizen console apps generally do. CSI is logically-speaking more than a compiler. It's used for running scripts in addition to compiling them, with compilation being only an intermediate and transparent step. For a pure compiler tool like csc.exe, it's job is to compile so it's normal or standard output is the result of compilation (errors, warnings, etc.). On the other hand, a script throwing an error (and we're not talking about a compilation error in the script here) should behave like a compiled console app. You emit errors to STDERR to not corrupt STDOUT. Just consider the original example again. The script failed but log.txt is empty. If the script had written partial results to STDOUT or another data file, then the result would be corrupted.

[atifaziz]

Would also make it consistent with FSI…

Without any redirection of STDOUT or STDERR:

echo raise^<int^> (System.Exception("BOOM!"))> test.fsx && fsi test.fsx || echo NOK

Prints:

System.Exception: BOOM!
   at <StartupCode$FSI_0001>.$FSI_0001.main@() in A:\test.fsx:line 1
Stopped due to error
NOK

With redirection of STDERR to nul device:

A:\>echo raise^<int^> (System.Exception("BOOM!"))> test.fsx && fsi test.fsx 2>nul || echo NOK

Prints just and as one would be expect:

NOK

[tmat]

Agreed.

[tmat]

However the right fix is to add

            catch (Exception e)
            {
                DisplayException(e);
                return false;
            }

to http://source.roslyn.io/#Microsoft.CodeAnalysis.Scripting/Hosting/CommandLine/CommandLineRunner.cs,181
and change DisplayException to print the error to STDERR.

Then of course tests need to be updated.

[atifaziz]

@tmat Right. I can look into that but we agree that the fix would technically be needed in both places?

[tmat]

Yes. Please file an issue for DisplayException. I think we can accept this PR.
👍

[atifaziz]

Do we need to change the tests at all? We can leave the existing tests using the same stream for both Error and Out. That way we are testing the common user experience on the console.

Then we can have just one or two tests that separate the streams and verify content of each stream separately.

@tmat So that's exactly what I have done. I added a tee-like writer so the error stream also writes to the output stream in addition to capturing its own text. I updated the tests where necessary to check the error stream content and everything seems to be passing:

xunit.console.x86.exe Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.dll -noshadow 

Output:

xUnit.net Console Runner (32-bit .NET 4.0.30319.42000)
  Discovering: Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests
  Discovered:  Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests
  Starting:    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests
    Microsoft.CodeAnalysis.CSharp.Scripting.Hosting.UnitTests.ObjectFormatterTests.StackTrace_Dynamic [SKIP]
      https://github.com/dotnet/roslyn/issues/9221
    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.InteractiveSessionTests.HostObjectAssemblyReference3 [SKIP]
      https://github.com/dotnet/roslyn/issues/6532
    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.InteractiveSessionTests.UsingExternalAliasesForHiding [SKIP]
      https://github.com/dotnet/roslyn/issues/6015
    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.InteractiveSessionTests.HostObjectAssemblyReference1 [SKIP]
      https://github.com/dotnet/roslyn/issues/8332
0




42
42
    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.ScriptTests.TestRunDynamicVoidScriptWithoutTerminatingSemicolon [SKIP]
      https://github.com/dotnet/roslyn/issues/170
    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests.ScriptTests.TestRunDynamicVoidScriptWithTerminatingSemicolon [SKIP]
      https://github.com/dotnet/roslyn/issues/170
  Finished:    Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests
=== TEST EXECUTION SUMMARY ===
   Microsoft.CodeAnalysis.CSharp.Scripting.UnitTests  Total: 211, Errors: 0, Failed: 0, Skipped: 6, Time: 23.684s

[atifaziz]

Fixed regression introduced by 92999b7:

Tests passed locally:

xUnit.net Console Runner (32-bit .NET 4.0.30319.42000)
  Discovering: Microsoft.CodeAnalysis.CSharp.Scripting.Desktop.UnitTests
  Discovered:  Microsoft.CodeAnalysis.CSharp.Scripting.Desktop.UnitTests
  Starting:    Microsoft.CodeAnalysis.CSharp.Scripting.Desktop.UnitTests
    Microsoft.CodeAnalysis.CSharp.Scripting.Hosting.UnitTests.CsiTests.CurrentWorkingDirectory_Change [SKIP]
      https://github.com/dotnet/roslyn/issues/7826
    Microsoft.CodeAnalysis.CSharp.Scripting.Test.InteractiveSessionTests.References1 [SKIP]
      xunit2
  Finished:    Microsoft.CodeAnalysis.CSharp.Scripting.Desktop.UnitTests
=== TEST EXECUTION SUMMARY ===
   Microsoft.CodeAnalysis.CSharp.Scripting.Desktop.UnitTests  Total: 32, Errors: 0, Failed: 0, Skipped: 2, Time: 11.374s

[atifaziz]

Anything keeping from this being merged?

[tmat]

👍