Keep an eye on IUK build performance in Jenkins

With the implementation of #17658 (closed), we are now using two jobs to build IUKs in parallel:

• parallel_build_IUKs: which triggers one sub-job per version, actually creating IUKs;
• parallel_collect_IUKs: which gather artifacts generated by the first one, and lumps them all together, along with a checksum for quick “all green?” verification.

The latter used to run quite quickly, as it just needs to copy artifacts over, gather all IUKs at the top-level (they all come with some intermediate directories), and run sha256sum. I was quite surprised to see it take roughly 15 minutes for 4.7.

On 2020-04-06, for Tails 4.5 → https://jenkins.tails.boum.org/view/RM/job/parallel_collect_IUKs/6/console (the job was renamed in the meanwhile):

22:35:13 Copied 1 artifact from "kibi_build_IUKs » 4.0,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:17 Copied 1 artifact from "kibi_build_IUKs » 4.0~beta1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:22 Copied 1 artifact from "kibi_build_IUKs » 4.0~beta2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:26 Copied 1 artifact from "kibi_build_IUKs » 4.0~rc1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:29 Copied 1 artifact from "kibi_build_IUKs » 4.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:32 Copied 1 artifact from "kibi_build_IUKs » 4.1.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:34 Copied 1 artifact from "kibi_build_IUKs » 4.2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:37 Copied 1 artifact from "kibi_build_IUKs » 4.2.2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:39 Copied 1 artifact from "kibi_build_IUKs » 4.3,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:41 Copied 1 artifact from "kibi_build_IUKs » 4.4,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:43 Copied 1 artifact from "kibi_build_IUKs » 4.4.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10
22:35:44 Copied 1 artifact from "kibi_build_IUKs » 4.5~rc1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 10

See how each copy took a few seconds.

Similar behaviour on 2020-05-05 for Tails 4.6 → https://jenkins.tails.boum.org/view/RM/job/parallel_collect_IUKs/7/console

But on 2020-06-02 for Tails 4.7 → https://jenkins.tails.boum.org/view/RM/job/parallel_collect_IUKs/9/console

there was quite an increase, around 30-60 seconds per copy.

21:27:36 Copied 1 artifact from "parallel_build_IUKs » 4.0,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:28:28 Copied 1 artifact from "parallel_build_IUKs » 4.0~beta1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:29:21 Copied 1 artifact from "parallel_build_IUKs » 4.0~beta2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:30:03 Copied 1 artifact from "parallel_build_IUKs » 4.0~rc1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:30:39 Copied 1 artifact from "parallel_build_IUKs » 4.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:31:20 Copied 1 artifact from "parallel_build_IUKs » 4.1.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:31:52 Copied 1 artifact from "parallel_build_IUKs » 4.2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:32:25 Copied 1 artifact from "parallel_build_IUKs » 4.2.2,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:32:55 Copied 1 artifact from "parallel_build_IUKs » 4.3,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:33:25 Copied 1 artifact from "parallel_build_IUKs » 4.4,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:33:48 Copied 1 artifact from "parallel_build_IUKs » 4.4.1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:34:11 Copied 1 artifact from "parallel_build_IUKs » 4.5,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:34:32 Copied 1 artifact from "parallel_build_IUKs » 4.5~rc1,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13
21:34:50 Copied 1 artifact from "parallel_build_IUKs » 4.6,isobuilder1 || isobuilder2 || isobuilder3 || isobuilder4" build number 13

Was Jenkins just loaded with other jobs that made I/O much slower? Or is there another issue that should be tracked down?

For some reasons, I'm not seeing the old builds of the upstream project → https://jenkins.tails.boum.org/view/RM/job/parallel_build_IUKs/ but I think each IUK generation took longer during 4.7 than during the last two releases. This will need to be checked for the next few releases…

Overall, that wasn't too bad though, the upstream job took 1h06, the downstream one took 0h17. Way better than building serially anyway…