[rush] Replay logs for warnings and errors as well

[aramissennyeydd]

Summary

Replays logs through the hook context's runWithTerminalAsync to hook into the stdio summarization functionality. This allows the report at the end of execution to be the same across machines.

Operations with 2 second durations were executed on the agent, those with <.5 seconds were restored from the build cache from the cobuild.

Before:

Agent 1

==[ SUCCESS WITH WARNINGS: 7 operations ]======================================

--[ WARNING: b (build) ]-------------------------------------[ 2.10 seconds ]--

done b

--[ WARNING: c (build) ]-------------------------------------[ 2.10 seconds ]--

done 

--[ WARNING: d (build) ]-------------------------------------[ 2.10 seconds ]--

done 

--[ WARNING: a (build) ]-------------------------------------[ 0.01 seconds ]--


--[ WARNING: e (build) ]-------------------------------------[ 2.09 seconds ]--

done 

--[ WARNING: f (build) ]-------------------------------------[ 2.13 seconds ]--

done f

--[ WARNING: g (build) ]-------------------------------------[ 2.14 seconds ]--

done g


Operations succeeded with warnings.

rush cobuild (16.95 seconds)

Agent 2

==[ SUCCESS WITH WARNINGS: 7 operations ]======================================

--[ WARNING: b (build) ]-------------------------------------[ 0.02 seconds ]--


--[ WARNING: c (build) ]-------------------------------------[ 0.01 seconds ]--


--[ WARNING: d (build) ]-------------------------------------[ 0.01 seconds ]--


--[ WARNING: a (build) ]-------------------------------------[ 2.10 seconds ]--

done a

--[ WARNING: e (build) ]-------------------------------------[ 0.02 seconds ]--


--[ WARNING: f (build) ]-------------------------------------[ 2.14 seconds ]--

done f

--[ WARNING: g (build) ]-------------------------------------[ 2.13 seconds ]--

done g


Operations succeeded with warnings.

rush cobuild (20.71 seconds)

After:

Agent 1

==[ SUCCESS WITH WARNINGS: 7 operations ]======================================

--[ WARNING: b (build) ]-------------------------------------[ 0.01 seconds ]--

done b

--[ WARNING: c (build) ]-------------------------------------[ 0.01 seconds ]--

done 

--[ WARNING: d (build) ]-------------------------------------[ 0.01 seconds ]--

done 

--[ WARNING: a (build) ]-------------------------------------[ 2.09 seconds ]--

done a

--[ WARNING: e (build) ]-------------------------------------[ 0.01 seconds ]--

done 

--[ WARNING: f (build) ]-------------------------------------[ 2.14 seconds ]--

done f

--[ WARNING: g (build) ]-------------------------------------[ 2.14 seconds ]--

done g


Operations succeeded with warnings.

Agent 2

==[ SUCCESS WITH WARNINGS: 7 operations ]======================================

--[ WARNING: b (build) ]-------------------------------------[ 2.09 seconds ]--

done b

--[ WARNING: c (build) ]-------------------------------------[ 2.08 seconds ]--

done 

--[ WARNING: d (build) ]-------------------------------------[ 2.09 seconds ]--

done 

--[ WARNING: a (build) ]-------------------------------------[ 0.01 seconds ]--

done a

--[ WARNING: e (build) ]-------------------------------------[ 2.09 seconds ]--

done 

--[ WARNING: f (build) ]-------------------------------------[ 2.14 seconds ]--

done f

--[ WARNING: g (build) ]-------------------------------------[ 2.14 seconds ]--

done g


Operations succeeded with warnings.

rush cobuild (16.92 seconds)

Details

This stores the log chunks into a JSON file, that is a direct write of the ITerminalChunk type. This is then restored while the build cache is being restored to the terminal with the correct severity following the ShellOperationPlugin logging semantics.

{
  "chunks": [
    {
      "kind": "O",
      "text": "Invoking: node ../build.js b \n"
    },
    {
      "kind": "O",
      "text": "start b\n"
    },
    {
      "kind": "E",
      "text": "done b\n",
    }
  ]
}

How it was tested

Tested against the repo cobuild sandbox with build caching enabled. Both restoring from the original build cache and cobuild cache work as expected and display the output above.

Impacted documentation

[iclanton]

This overall looks good to me, but it'd be good for @octogonz to review this too, as he originally wrote a lot of the streaming logs stuff.

[aramissennyeydd]

@octogonz @dmichon-msft This is ready for re-review when you get a chance!

[iclanton]

How painful would it be to add a unit test for the chunked file format?

[iclanton]

@aramissennyeydd - Looks good overall. Once you just address @dmichon-msft's comments we can get this in.

[aramissennyeydd]

@iclanton Added a unit test as well for the log restoration in OperationMetadataManager.