races in console trace while running Shell.Exec

[zhongjn]

Description

While running commands with Shell.Exec, output from stdout or stderr gets wrong.

Repro steps

1. Step A
   Prepare a bash script err.sh:

>&2 echo err1 # writes to stderr
>&1 echo out1 # writes to stdout
>&2 echo err2
>&1 echo out2
sleep 1

2. Step B
   Use Shell.Exec to execute the bash script. I executed the script multiple times here to make the problem more obvious.

Shell.Exec("bash", "scripts/err.sh") |> ignore
Shell.Exec("bash", "scripts/err.sh") |> ignore
Shell.Exec("bash", "scripts/err.sh") |> ignore

Expected behavior

Output are colored accordingly. Lines are not messed up.

Actual behavior

Known workarounds

Please provide a description of any known workarounds.

Related information

• Operating system: Ubuntu 20.04
• .NET Runtime: 6.0
• Version of FAKE: latest

[github-actions]

Welcome to the FAKE community! Thank you so much for creating your first issue and therefore improving the project!

[zhongjn]

The root cause shold be:

1. While running the command, callbacks are executed in different threads:

FAKE/src/app/Fake.Core.Process/Process.fs

Lines 843 to 850 in 79aa127

	proc.ErrorDataReceived.Add(fun e ->
	if not (isNull e.Data) then Trace.traceError e.Data)
	proc.OutputDataReceived.Add(fun e ->
	if not (isNull e.Data) then Trace.log e.Data)
	rawStartProcess proc
	proc.BeginOutputReadLine()
	proc.BeginErrorReadLine()
	proc.StandardInput.Dispose()

2. Trace is not thread-safe, since ConsoleTraceListener is not thread-safe:

FAKE/src/app/Fake.Core.Trace/TraceListener.fs

Lines 273 to 308 in 79aa127

	type ConsoleTraceListener(importantMessagesToStdErr, colorMap, ansiColor) =
	interface ITraceListener with
	/// Writes the given message to the Console.
	member __.Write msg =
	let color = colorMap msg
	let write = if ansiColor then ConsoleWriter.writeAnsiColor else ConsoleWriter.write
	match msg with
	| TraceData.ImportantMessage text | TraceData.ErrorMessage text ->
	write importantMessagesToStdErr color true text
	| TraceData.LogMessage(text, newLine) | TraceData.TraceMessage(text, newLine) ->
	write false color newLine text
	| TraceData.OpenTag(KnownTags.Target _ as tag, description)
	| TraceData.OpenTag(KnownTags.FailureTarget _ as tag, description)
	| TraceData.OpenTag(KnownTags.FinalTarget _ as tag, description) ->
	let color2 = colorMap (TraceData.TraceMessage("", true))
	match description with
	| Some d -> write false color2 true (sprintf "Starting %s '%s': %s" tag.Type tag.Name d)
	| _ -> write false color2 true (sprintf "Starting %s '%s'" tag.Type tag.Name)
	| TraceData.OpenTag (tag, description) ->
	match description with
	| Some d -> write false color true (sprintf "Starting %s '%s': %s" tag.Type tag.Name d)
	| _ -> write false color true (sprintf "Starting %s '%s'" tag.Type tag.Name)
	| TraceData.CloseTag (tag, time, status) ->
	write false color true (sprintf "Finished (%A) '%s' in %O" status tag.Name time)
	| TraceData.ImportData (typ, path) ->
	write false color true (sprintf "Import data '%O': %s" typ path)
	| TraceData.BuildState (state, None) ->
	write false color true (sprintf "Changing BuildState to: %A" state)
	| TraceData.BuildState (state, Some message) ->
	write false color true (sprintf "Changing BuildState to: %A - %s" state message)
	| TraceData.TestOutput (test, out, err) ->
	write false color true (sprintf "Test '%s' output:\n\tOutput: %s\n\tError: %s" test out err)
	| TraceData.BuildNumber number ->
	write false color true (sprintf "Build Number: %s" number)
	| TraceData.TestStatus (test, status) ->
	write false color true (sprintf "Test '%s' status: %A" test status)

Could we simply make ConsoleTraceListener thread-safe to fix this problem? If so, i could make a PR to fix this.

[yazeedobaid]

Thanks for reporting. Can you please use the create process API instead? Since the asyncShellExex is marked with an obsolete attribute.

FAKE/src/app/Fake.Core.Process/Process.fs

Lines 826 to 829 in 79aa127

	[<System.Obsolete("use the CreateProcess APIs instead.")>]
	let asyncShellExec (args : ExecParams) =
	async {
	if String.isNullOrEmpty args.Program then invalidArg "args" "You must specify a program to run!"