It looks like each task has around an 8 second penalty startup time here, on each integration test that gets run:

2019/07/19 16:41:58 Running command: /usr/bin/id -u
2019/07/19 16:41:58 Running command: /usr/bin/id -g
2019/07/19 16:41:58 All features initialised.
2019/07/19 16:41:58 Running command: /usr/bin/id -u
2019/07/19 16:41:58 Running command: /usr/bin/id -g
2019/07/19 16:41:58 Checking if user is logged in...
2019/07/19 16:41:58 Running command: /usr/bin/last -t console -1
2019/07/19 16:42:02 User task_1563567976 logged in at 2019-07-19 16:34:25.41329206 -0400 EDT
2019/07/19 16:42:02 Running command: /usr/bin/last -t console -1
2019/07/19 16:42:06 Granting task_1563567976 control of /Users/task_1563567976/gopath1.10.8/src/github.com/taskcluster/generic-worker/testdata/TestCacheMoved/task_1563567976

A couple of inefficiencies stand out: the id command results are not cached so are run multiple times (although run very quickly) but also the last command takes around 4 seconds, is also run twice, and its results are also not cached.

We should see if it is worth disabling the last command for CI tests (or mocking it, etc) or perhaps find a more efficient way to check which user has the console session, and we should look at caching results of expensive queries. We could also potentially run tests in parallel (go supports this natively) to get a potentially huge performance gain, but before we can do that, we may need to clean up the use of global variables used in generic-worker, so that might be something for another bug.

This bug is about getting rid of the current ~8s penalty we hit for every integration test that calls RunWorker, or reducing it considerably. This should significantly reduce the overall time it takes the CI tasks to run.

It occurs to me, if we simply cache the results of the last command, that cached value will persist across tests, meaning we'll solve the 8s delay problem, and probably reduce the test runtime by around 20 mins!

Released in generic-worker 15.1.4.