Taskcluster tasks sometimes hang at the end

[jgraham]

It looks like we have tasks that do all the work but don't exit properly. I guess it's some race condition during shutdown that may be exacerbated by printing a lot of logs about unexpected failures at the end. For example:

https://tools.taskcluster.net/groups/HbE1r6PHR-K6dVfjVBCyyg/tasks/EyHx_c0rTKeGvgSTyLeJBw/runs/0/logs/public%2Flogs%2Flive.log

[jugglinmike]

I reviewed TaskCluster's behavior for all the builds between July 6 and July 12:

• July 12 - 18 commites executed
  • https://tools.taskcluster.net/groups/ISbN6zidQLOm_TlZ9WdY9w
    • wpt-firefox-nightly-testharness-11: wpt run interrupted
    • wpt-firefox-nightly-testharness-4: wpt run interrupted
  • https://tools.taskcluster.net/groups/MPwEVXu-RVihB6jL3ajAUA
    • wpt-firefox-nightly-testharness-11: wpt run interrupted
  • https://tools.taskcluster.net/groups/eaNGKJtNSp-I2zNhuGqWxA
    • wpt-firefox-nightly-testharness-2: wpt run interrupted
  • https://tools.taskcluster.net/groups/QYP7w2gcQJ2Lb_A4CziT3g
    • wpt-firefox-nightly-testharness-3: wpt run interrupted
  • https://tools.taskcluster.net/groups/aBZ1G4bRSQCY7MQq5fLurg
    • wpt-chrome-dev-testharness-15: wpt run completed
    • wpt-firefox-nightly-testharness-4: wpt run completed
• July 11 - 13 commits executed
  • (zero failures)
• July 10 - 26 commits executed
  • https://tools.taskcluster.net/groups/JCVPZgBeS5ur-bmIwcEWSw
    • wpt-firefox-nightly-testharness-1: wpt run completed
    • wpt-firefox-nightly-testharness-11: wpr run interrupted
  • https://tools.taskcluster.net/groups/K4YrvjLKSfua_6MUtnH2_g
    • wpt-firefox-nightly-testharness-11: wpt run completed
  • https://tools.taskcluster.net/groups/W9-NIkPLQ8aeoyux1LAPmw
    • wpt-firefox-nightly-testharness-8: wpt run completed
  • https://tools.taskcluster.net/groups/cMsqG1DORSCT_PQnCPD9YQ
    • widespread failures
• July 9 - 14 commites executed
  • https://tools.taskcluster.net/groups/IKVL5UESRzuKl2A2ymGdEA
    • wpt-chrome-dev-testharness-5: wpt-run completed
    • wpt-firefox-nightly-testharness-11: wpt run interrupted
• July 8 - 2 commits executed
  • https://tools.taskcluster.net/groups/KOKn9JrdSX-d9HQLRKN02Q
    • wpt-firefox-nightly-testharness-3: wpt run interrupted
• July 7 - 3 commits executed
  • (zero failures)
• July 6 - 15 commits executed
  • https://tools.taskcluster.net/groups/c0dpVpuFS6uvblcKO0ZxdQ
    • wpt-chrome-dev-testharness-3: wpt run completed
  • https://tools.taskcluster.net/groups/Dlyz_GHRTeSS5K7g-UmzxQ
    • wpt-firefox-nightly-testharness-14: wpt run completed
  • https://tools.taskcluster.net/groups/ESalQKeBQHWEhr7-LtmSqg
    • wpt-firefox-nightly-testharness-4: wpt run interrupted

As noted, not all of those hang at the end. Many pause in the middle of test execution. After some trial-and-error, I was able to reproduce the problem locally using a generic Ubuntu 16.04 container and zero additional dependencies:

$ docker run -t --rm  ubuntu:16.04 bash -c 'seq $((2 ** 30))'

That process will eventually stall. If you run the command with --interactive, you'll find that it's waiting for terminal input--press any key, and it will continue.

I wrote up a very professional and impressive bug report for Docker, but I just now found the problem being discussed in the context of the Moby project, so you'll have to take my word for it.

It's hanging after an EIO error from the terminal. The hang is a bug but the
EIO is real. What is the use case for piping a ton of data through a
container with a pty? It's less overhead, fast, and no linux pty complexity
to just remove the -t from the container if you are doing these types of
things.

And the response is relevant:

For us it’s a ci system :)

Fortunately, someone has come through with a patch to containerd/console (yet another component of the project--Docker is complex!), so we can hope that this will resolve itself in time.

I don't know what the time frame is, though. The change will need to be released in Docker, and TaskCluster will need to migrate to the new version. That's a lot of moving parts. In the mean time, we could experiment with throttling standard output and standard error. What do you think @jgraham?

[jugglinmike]

Here's some discussion about the issue on the TaskCluster bug tracker: https://bugzilla.mozilla.org/show_bug.cgi?id=1457694

[jugglinmike]

The bug fix has been published in Docker version 18.06, and the folks at TaskCluster have updated to that release. With that change live in TaskCluster, we just need to wait and see if stability improves on WPT's master branch. If we're lucky, my terrible "throttle standard output" script will never see the light of day.

[jugglinmike]

It's been a week since the folks at TaskCluster deployed the fix, and of the 56 TaskCluster builds which have run, zero have failed. Although this evidence is not as conclusive as, say, a passing unit test, the nature of the problem makes it difficult to be more precise.

@jgraham are you satisfied by these results? Do you think it's fair to call this issue resolved?

[jgraham]

I am very pleased to do so.