Add timings to verbose output #1105
Conversation
| now <- Effect.liftEffect $ Now.now | ||
| let | ||
| (timeDiff :: Milliseconds) = Instant.diff now logOptions.startingTime | ||
| millisDoc = Ansi.foreground Ansi.White $ Ansi.bold $ Log.text $ Strings.padStart 8 $ show $ Int.round $ unwrap timeDiff |
There was a problem hiding this comment.
This is so much nicer than the million time/timeEnds I was dropping in before!
Given that the times just ascend is the padding necessary? I'd find this hard to parse:
[80ms] ...
[802323ms] ...
[802ms] ...
But not so much this:
[4ms] ...
[10ms] ...
[75ms] ...
[80ms] ...
[2000ms] ...
[32322ms] ...
Maybe it's more noticeably jumpy at the start. Could drop it down to 4 so the nudge only happens after longer intervals?
| millisDoc = Ansi.foreground Ansi.White $ Ansi.bold $ Log.text $ Strings.padStart 8 $ show $ Int.round $ unwrap timeDiff | |
| millisDoc = Ansi.foreground Ansi.White $ Ansi.bold $ Log.text $ Strings.padStart 4 $ show $ Int.round $ unwrap timeDiff |
There was a problem hiding this comment.
But not so much this
My eye finds that equally hard to parse, and I figured out because I started with what you're suggesting here, and ended up with the padding 😄
There was a problem hiding this comment.
I am unsure about the square brackets though. I just wanted some separation with the rest of the log line, I guess a dash or something could work as well
There was a problem hiding this comment.
I don't think I care one way or another whether there's brackets or hyphens used.
I do like the current padded usage.
This PR adds to the verbose output the amount of milliseconds elapsed from the beginning of the execution, so that it's easier to find slow bits that can be sped up.
cc @JordanMartinez @finnhodgkin
It looks something like this (bikeshedding on how they should look like is welcome):