[RFC ...] elapsed time in progress reporters - WIP FOR DISCUSSION

[brody4hire]

First draft for elapsed time in progress reporters, as discussed in stryker-mutator#1844:

• show elapsed time, with seconds if <60 minutes
• change ETC label to remaining
• no remaining time seconds if >59 minutes

I think this is not the best UX. When I tried it with Prettier (with Stryker configured as shown in brody4hire/prettier#16), I got the following output in the beginning with elapsed time frozen at "1m, 37s":

$ node --max-old-space-size=100000 ./node_modules/.bin/stryker run
14:19:42 (5020) INFO ConfigReader Using stryker.conf.js in the current working directory.
14:19:43 (5020) INFO InputFileResolver Found 13 of 5927 file(s) to be mutated.
14:19:43 (5020) INFO InitialTestExecutor Starting initial test run. This may take a while.
14:21:11 (5020) INFO InitialTestExecutor Initial test run succeeded. Ran 1 tests in 1 minute 28 seconds (net 88012 ms, overhead 1 ms).
14:21:12 (5020) INFO MutatorFacade 1186 Mutant(s) generated
14:21:12 (5020) INFO SandboxPool Creating 4 test runners (based on CPU count)
Mutation testing  [                                               ] 0% (elapsed: 1m, 37s) (remaining: 15h, 57m) 2/1186 tested (0 survived, 0 timed out)

After a couple more minutes, frozen again:

Mutation testing  [                                               ] 0% (elapsed: 3m, 36s) (remaining: 23h, 39m) 3/1186 tested (0 survived, 0 timed out)

Here are some results from the append-only progress reporter:

$ node --max-old-space-size=100000 ./node_modules/.bin/stryker run | tee tt1
14:26:46 (5696) INFO ConfigReader Using stryker.conf.js in the current working directory.
14:26:47 (5696) INFO BroadcastReporter Detected that current console does not support the "progress" reporter, downgrading to "progress-append-only" reporter
14:26:48 (5696) INFO InputFileResolver Found 13 of 5928 file(s) to be mutated.
14:26:48 (5696) INFO InitialTestExecutor Starting initial test run. This may take a while.
14:28:17 (5696) INFO InitialTestExecutor Initial test run succeeded. Ran 1 tests in 1 minute 30 seconds (net 88276 ms, overhead 1 ms).
14:28:17 (5696) INFO MutatorFacade 1186 Mutant(s) generated
14:28:17 (5696) INFO SandboxPool Creating 4 test runners (based on CPU count)
Mutation testing 0% (elapsed: 10s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 20s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 30s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 40s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 50s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 0s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 10s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 20s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 30s) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 40s) (remaining: 16h, 26m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m, 50s) (remaining: 18h, 5m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2m, 0s) (remaining: 19h, 44m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2m, 10s) (remaining: 21h, 22m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2m, 20s) (remaining: 23h, 1m) 2/1186 tested (0 survived, 0 timed out)

[brody4hire]

I tried making an update in my local workarea, using decimal minutes instead of minutes & seconds, and using Yarn to install the updates locally in my Prettier workarea, no change in output. The reason is that I forgot to do npm run build to update the JavaScript from the TypeScript.

This misstep cost me some time waiting for Yarn install, Stryker run, and cleanup in my Prettier workarea. I am pretty new at TypeScript but am not so happy I have to deal with this kind of hurdle. I have nicer experience with using JSDoc for type linting ref:

• https://medium.com/@trukrs/javascript-type-linting-5903e9e3625f
• [...] Start JSDoc type linting prettier/prettier#6770

[brody4hire]

I tried updating ProgressKeeper.ts to show time in hours & minutes with decimals (with no unit test updates yet), go the following initial results from stryker run:

$ node --max-old-space-size=100000 ./node_modules/.bin/stryker run
14:59:53 (7291) INFO ConfigReader Using stryker.conf.js in the current working directory.
14:59:53 (7291) INFO InputFileResolver Found 13 of 5928 file(s) to be mutated.
14:59:53 (7291) INFO InitialTestExecutor Starting initial test run. This may take a while.
15:01:24 (7291) INFO InitialTestExecutor Initial test run succeeded. Ran 1 tests in 1 minute 30 seconds (net 89622 ms, overhead 2 ms).
15:01:24 (7291) INFO MutatorFacade 1186 Mutant(s) generated
15:01:24 (7291) INFO SandboxPool Creating 4 test runners (based on CPU count)
Mutation testing  [                                               ] 0% (elapsed: 1.61m) (remaining: 15h, 57.06m) 2/1186 tested (0 survived, 0 timed out)

and after a couple more minutes:

Mutation testing  [                                               ] 0% (elapsed: 3.45m) (remaining: 22h, 40.45m) 3/1186 tested (0 survived, 0 timed out)

Output from append-only progress reporter is coming next.

[brody4hire]

Here is some output from downgrade to "progress-append-only" reporter:

$ node --max-old-space-size=100000 ./node_modules/.bin/stryker run | tee tt2
15:06:47 (7966) INFO ConfigReader Using stryker.conf.js in the current working directory.
15:06:47 (7966) INFO BroadcastReporter Detected that current console does not support the "progress" reporter, downgrading to "progress-append-only" reporter
15:06:48 (7966) INFO InputFileResolver Found 13 of 5929 file(s) to be mutated.
15:06:48 (7966) INFO InitialTestExecutor Starting initial test run. This may take a while.
15:08:20 (7966) INFO InitialTestExecutor Initial test run succeeded. Ran 1 tests in 1 minute 33 seconds (net 91186 ms, overhead 1 ms).
15:08:21 (7966) INFO MutatorFacade 1186 Mutant(s) generated
15:08:21 (7966) INFO SandboxPool Creating 4 test runners (based on CPU count)
Mutation testing 0% (elapsed: 0.16m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 0.33m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 0.5m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 0.66m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 0.83m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1.16m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1.33m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1.5m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1.66m) (remaining: n/a) 0/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 1.83m) (remaining: 18h, 5.33m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2m) (remaining: 19h, 44m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2.16m) (remaining: 21h, 22.66m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2.33m) (remaining: 23h, 1.33m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2.5m) (remaining: 24h, 40m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2.66m) (remaining: 26h, 18.66m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 2.83m) (remaining: 27h, 57.33m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3m) (remaining: 29h, 36m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3.16m) (remaining: 31h, 24.53m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3.38m) (remaining: 33h, 22.93m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3.55m) (remaining: 35h, 1.6m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3.71m) (remaining: 36h, 40.26m) 2/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 3.88m) (remaining: 25h, 31.31m) 3/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 4.05m) (remaining: 26h, 37.05m) 3/1186 tested (0 survived, 0 timed out)
Mutation testing 0% (elapsed: 4.21m) (remaining: 27h, 42.76m) 3/1186 tested (0 survived, 0 timed out)

[brody4hire]

I think the UX with hours & decimal minutes is cleaner than showing seconds for < 60 minutes.

I just pushed a few more updates:

• update the unit tests
• added some comments to avoid some unwanted ESLint/Prettier reformatting
• minor ESLint/Prettier reformatting of expressions used for time formatting

Build should be green now.

I am now planning to raise a PR on Stryker with these changes, with git rebase to clean the history up a bit

I suspect there should be a way to improve the progress reporter UX further, and it may be good to consider using an external time formatting library such as moment.js.