fix(timeline,cobuilds): cobuilt operations should reflect the cobuild time and not cache restore time

[aramissennyeydd]

Summary

OperationExecutionRecord is currently only tracking cache restore time for cobuilt operations that are marked as RemoteOperating and are then restored from cache. This is a confusing UX and causes developers + maintainers to have to search across multiple machine logs to determine operation run times. This PR adjusts that to use the nonCachedDurationMs from the state file. This felt like something that #3649 was intending to do or is in a similar vein.

Before:

After:

Details

This overwrites the existing stopwatch for operations that were not cobuilt on the specific agent. It adds a new beforeResult method to OperationExecutionRecord#executeAsync to handle the afterExecuteOperation hook instead of passing that work into the onResult method which ended up receiving running stopwatches and had other assumptions of state (collated terminal not closed). This does add possibly breaking behavior where cobuilds were showing cache times which might be useful, but I don't think those are as useful as having the cobuild time available across all agents. That also has the secondary effect of making the timeline views of all agents much more cohesive - though as we see above they're not the exact same across agents.

How it was tested

I tested this locally using the build-tests/rush-redis-cobuild-plugin-integration-test sandbox repo with 2 runners, confirmed that timings generally matched across the instances. There's about 10ms (rounded up) of difference between the agents, but this already seems much more useful.

Impacted documentation

None

[aramissennyeydd]

Small adjustment to improve the dependency view, previously they were getting smushed into the same time slot, when they should be sequential.

[aramissennyeydd]

And a few screen grabs from our internal instance showing the difference from the small adjustment,

Before

After

[UberMouse]

Any reason this hasn't been merged? It's a real problem trying to work out performance of co-build enabled builds 😬

[aramissennyeydd]

@UberMouse Lost track of this, I was waiting on #4755 to get merged so we didn't cause more telemetry skew with this.

[iclanton]

@aramissennyeydd - this should be unblocked now.

[aramissennyeydd]

@iclanton This should be good for another round of 👀 🙏

[aramissennyeydd]

Should the stopwatch time include the before + after timings? The big issue right now is that when we go to report the times, the stopwatch hasn't ended so endTime is undefined.

[dmichon-msft]

Wait, why hasn't it ended? Are we bypassing the code path that would tell it to stop()?

[aramissennyeydd]

We've been calling .stop in the finally block, which runs after onResult, this wasn't an issue really until now since the toString and duration use the current time as a fallback 😞