[Bug 1384324] [NEW] eternal adt-run hang with timeouts in ssh

[Martin Pitt]

Public bug reported:

With the ssh runner and nova, we are getting eternal hangs of adt-run
after a timeout:

test_4_special (tests.test_transport.TransportTest) ... adt-run
[16:13:52]: ERROR: testbed failed: timed out on command "env
LANG=C.UTF-8 su -s /bin/bash ubuntu -c set -e; export USER=`id -nu`; .
/etc/profile >/dev/null 2>&1 || true;  . ~/.profile >/dev/null 2>&1 ||
true; buildtree="/tmp/adt-run.U3HzgO/build.mYT/paramiko-1.15.1"; mkdir
-p -m 1777 -- "/tmp/adt-run.U3HzgO/upstream-artifacts"; export
ADT_ARTIFACTS="/tmp/adt-run.U3HzgO/upstream-artifacts"; export
ADTTMP=$(mktemp -d --tmpdir adttmp.XXXXXX); trap "rm -rf $ADTTMP" EXIT
INT QUIT PIPE; chmod 755 $ADTTMP; cd "$buildtree"; export LANG=C.UTF-8;
chmod +x /tmp/adt-
run.U3HzgO/build.mYT/paramiko-1.15.1/debian/tests/upstream; touch /tmp
/adt-run.U3HzgO/upstream-stdout /tmp/adt-run.U3HzgO/upstream-stderr;
/tmp/adt-run.U3HzgO/build.mYT/paramiko-1.15.1/debian/tests/upstream 2>
>(tee -a /tmp/adt-run.U3HzgO/upstream-stderr >&2) > >(tee -a /tmp/adt-
run.U3HzgO/upstream-stdout); " (kind: test)

At that time we have these around:

ubuntu    7395  0.1  0.6  56700 13468 pts/2    S+   16:12   0:00 /usr/bin/python3 -u /home/ubuntu/autopkgtest/runner/adt-run
ubuntu    7397  0.0  0.0   5920   704 pts/2    S+   16:12   0:00 tee /tmp/adt-out/paramiko/fifo_log -a /dev/stderr
ubuntu    7398  0.0  0.0   5936   620 pts/2    S+   16:12   0:00 cat /tmp/adt-out/paramiko/fifo_log

Killing the tee process (7397) makes it unstuck and cleans up.

It seems to be stuck here:

        def cleanup():
            os.close(sys.stdout.fileno())
            os.close(out_tee.stdin.fileno())
            out_tee.wait()
            os.close(sys.stderr.fileno())
            os.close(err_tee.stdin.fileno())
            err_tee.wait()
            log_cat.wait()

I. e. even though we close the tee's stdin, the tee process is still
waiting in read(0, ...), so closing its stdin isn't sufficient here for
some reason.

** Affects: autopkgtest (Ubuntu)
     Importance: High
     Assignee: Martin Pitt (pitti)
         Status: New

** Changed in: autopkgtest (Ubuntu)
   Importance: Undecided => High

** Changed in: autopkgtest (Ubuntu)
     Assignee: (unassigned) => Martin Pitt (pitti)

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to autopkgtest in Ubuntu.
https://bugs.launchpad.net/bugs/1384324

Title:
  eternal adt-run hang with timeouts in ssh

Status in “autopkgtest” package in Ubuntu:
  New

Bug description:
  With the ssh runner and nova, we are getting eternal hangs of adt-run
  after a timeout:

  test_4_special (tests.test_transport.TransportTest) ... adt-run
  [16:13:52]: ERROR: testbed failed: timed out on command "env
  LANG=C.UTF-8 su -s /bin/bash ubuntu -c set -e; export USER=`id -nu`; .
  /etc/profile >/dev/null 2>&1 || true;  . ~/.profile >/dev/null 2>&1 ||
  true; buildtree="/tmp/adt-run.U3HzgO/build.mYT/paramiko-1.15.1"; mkdir
  -p -m 1777 -- "/tmp/adt-run.U3HzgO/upstream-artifacts"; export
  ADT_ARTIFACTS="/tmp/adt-run.U3HzgO/upstream-artifacts"; export
  ADTTMP=$(mktemp -d --tmpdir adttmp.XXXXXX); trap "rm -rf $ADTTMP" EXIT
  INT QUIT PIPE; chmod 755 $ADTTMP; cd "$buildtree"; export
  LANG=C.UTF-8; chmod +x /tmp/adt-
  run.U3HzgO/build.mYT/paramiko-1.15.1/debian/tests/upstream; touch /tmp
  /adt-run.U3HzgO/upstream-stdout /tmp/adt-run.U3HzgO/upstream-stderr;
  /tmp/adt-run.U3HzgO/build.mYT/paramiko-1.15.1/debian/tests/upstream 2>
  >(tee -a /tmp/adt-run.U3HzgO/upstream-stderr >&2) > >(tee -a /tmp/adt-
  run.U3HzgO/upstream-stdout); " (kind: test)

  At that time we have these around:

  ubuntu    7395  0.1  0.6  56700 13468 pts/2    S+   16:12   0:00 /usr/bin/python3 -u /home/ubuntu/autopkgtest/runner/adt-run
  ubuntu    7397  0.0  0.0   5920   704 pts/2    S+   16:12   0:00 tee /tmp/adt-out/paramiko/fifo_log -a /dev/stderr
  ubuntu    7398  0.0  0.0   5936   620 pts/2    S+   16:12   0:00 cat /tmp/adt-out/paramiko/fifo_log

  Killing the tee process (7397) makes it unstuck and cleans up.

  It seems to be stuck here:

          def cleanup():
              os.close(sys.stdout.fileno())
              os.close(out_tee.stdin.fileno())
              out_tee.wait()
              os.close(sys.stderr.fileno())
              os.close(err_tee.stdin.fileno())
              err_tee.wait()
              log_cat.wait()

  I. e. even though we close the tee's stdin, the tee process is still
  waiting in read(0, ...), so closing its stdin isn't sufficient here
  for some reason.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/autopkgtest/+bug/1384324/+subscriptions