Baffling regress/forwarding.sh failure, new in 7.4p1

Colin Watson cjwatson at debian.org
Sat Dec 31 23:55:52 AEDT 2016


I have the OpenSSH regression tests hooked up to run in Debian and
Ubuntu's "autopkgtest" system, so that they're automatically run on
uploads of OpenSSH itself or any of its dependencies.  This is
especially good for enforcing interoperability between it and other SSH
implementations, but it's also pretty good for throwing up occasional
extremely-hard-to-debug failures since the only way I can get more
information out of the test nodes is to upload packages to Debian
unstable.

In this case I have a new failure in 7.4p1 that didn't occur in 7.3p1.
I'm seeing it on Debian amd64 and Ubuntu s390x, so from context I think
it's specific to the case where we're using autopkgtest's LXC
virtualisation mode.  I can run the tests locally, but so far haven't
managed to reproduce this failure that way.

I arranged to run all tests under TEST_SHELL='sh -x' and to dump
failed-{regress,ssh,sshd}.log on failures.  Can anyone make anything out
of this?

  run test forwarding.sh ...
  + _POSIX2_VERSION=199209
  + export _POSIX2_VERSION
  + uname -s
  + [ ! -z  ]
  + PORT=4242
  + [ -x /usr/ucb/whoami ]
  + whoami
  + whoami
  + USER=openssh-tests
  + OBJ=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress
  + [ x/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress = x ]
  + [ ! -d /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress ]
  + SCRIPT=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh
  + [ x/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh = x ]
  + [ ! -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh ]
  + sh -x -n /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh
  + true
  + unset SSH_AUTH_SOCK
  + dirname /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh
  + SRC=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress
  + SSH=ssh
  + SSHD=sshd
  + SSHAGENT=ssh-agent
  + SSHADD=ssh-add
  + SSHKEYGEN=ssh-keygen
  + SSHKEYSCAN=ssh-keyscan
  + SFTP=sftp
  + SFTPSERVER=/usr/libexec/openssh/sftp-server
  + SCP=scp
  + PLINK=plink
  + PUTTYGEN=puttygen
  + CONCH=conch
  + [ x != x ]
  + [ x != x ]
  + [ x != x ]
  + [ x != x ]
  + [ x != x ]
  + [ x != x ]
  + [ x != x ]
  + [ x/usr/lib/openssh/sftp-server != x ]
  + SFTPSERVER=/usr/lib/openssh/sftp-server
  + [ x != x ]
  + [ xplink != x ]
  + which plink
  + PLINK=/usr/bin/plink
  + [ xputtygen != x ]
  + which puttygen
  + PUTTYGEN=/usr/bin/puttygen
  + [ xconch != x ]
  + which conch
  + CONCH=/usr/bin/conch
  + SSH_PROTOCOLS=2
  + [ x != x ]
  + which sshd
  + SSHD=/usr/sbin/sshd
  + which ssh-agent
  + SSHAGENT=/usr/bin/ssh-agent
  + SSH_BIN=ssh
  + SSHD_BIN=/usr/sbin/sshd
  + SSHAGENT_BIN=/usr/bin/ssh-agent
  + SSHADD_BIN=ssh-add
  + SSHKEYGEN_BIN=ssh-keygen
  + SSHKEYSCAN_BIN=ssh-keyscan
  + SFTP_BIN=sftp
  + SFTPSERVER_BIN=/usr/lib/openssh/sftp-server
  + SCP_BIN=scp
  + [ x != x ]
  + [ x = x ]
  + TEST_SSH_LOGFILE=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh.log
  + [ x = x ]
  + TEST_SSHD_LOGFILE=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd.log
  + [ x = x ]
  + TEST_REGRESS_LOGFILE=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/regress.log
  + 
  + 
  + 
  + SSHLOGWRAP=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh
  + echo #!/bin/sh
  + echo exec ssh -E/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh.log "$@"
  + chmod a+rx /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh
  + REAL_SSH=ssh
  + SSH=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh
  + DATANAME=data
  + DATA=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/data
  + cat /usr/bin/ssh-agent
  + chmod u+w /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/data
  + COPY=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + rm -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + export SSH SSHD SSHAGENT SSHADD SSHKEYGEN SSHKEYSCAN SFTP SFTPSERVER SCP
  + RESULT=0
  + PIDFILE=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile
  + trap fatal 3 2
  + ssh_version 1
  + echo 2+ grep 1
  
  + PROTO=2
  + cat
  + [ ! -z  ]
  + [ ! -z  ]
  + cp /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_config /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_proxy
  + echo StrictModes no
  + cat
  + [ ! -z  ]
  + rm -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/known_hosts /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/authorized_keys_openssh-tests
  + ssh_version 1
  + echo 2
  + grep 1
  + SSH_KEYTYPES=rsa ed25519
  + trace generate keys
  + start_debug_log generate keys
  + echo trace: generate keys
  + echo trace: generate keys
  + echo trace: generate keys
  + [ X = Xyes ]
  + [ ! -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa ]
  + [ ssh-keygen -nt /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa ]
  + printf localhost-with-alias,127.0.0.1,::1 
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa.pub
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa.pub
  + echo IdentityFile /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa
  + sudo cp /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/host.rsa
  + echo HostKey /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/host.rsa
  + echo HostKey /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/rsa
  + [ ! -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519 ]
  + [ ssh-keygen -nt /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519 ]
  + printf localhost-with-alias,127.0.0.1,::1 
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519.pub
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519.pub
  + echo IdentityFile /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519
  + sudo cp /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519 /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/host.ed25519
  + echo HostKey /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/host.ed25519
  + echo HostKey /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ed25519
  + chmod 644 /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/authorized_keys_openssh-tests
  + REGRESS_INTEROP_CONCH=no
  + test -x /usr/bin/conch
  + REGRESS_INTEROP_CONCH=yes
  + REGRESS_INTEROP_PUTTY=no
  + test -x /usr/bin/puttygen -a -x /usr/bin/plink
  + REGRESS_INTEROP_PUTTY=yes
  + REGRESS_INTEROP_PUTTY=no
  + test no = yes
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config
  + echo proxycommand sudo sh /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd-log-wrapper.sh /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd.log /usr/sbin/sshd -i -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_proxy
  + /usr/sbin/sshd -t -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_proxy
  + . /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/forwarding.sh
  + tid=local and remote forwarding
  + DATA=/bin/ls
  + start_sshd
  + sudo /usr/sbin/sshd -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_config -t
  + sudo /usr/sbin/sshd -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd_config -E/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd.log
  + trace wait for sshd
  + start_debug_log wait for sshd
  + echo trace: wait for sshd
  + echo trace: wait for sshd
  + echo trace: wait for sshd
  + [ X = Xyes ]
  + i=0
  + [ ! -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile -a 0 -lt 10 ]
  + test -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile
  + base=33
  + last=4242
  + fwd=
  + CTL=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ctl-sock
  + rm -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ctl-sock
  + a=3300
  + expr 3300 + 50
  + b=3350
  + c=4242
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242
  + last=3300
  + a=3301
  + expr 3301 + 50
  + b=3351
  + c=3300
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300
  + last=3301
  + a=3302
  + expr 3302 + 50
  + b=3352
  + c=3301
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301
  + last=3302
  + a=3310
  + expr 3310 + 50
  + b=3360
  + c=3302
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302
  + last=3310
  + a=3311
  + expr 3311 + 50
  + b=3361
  + c=3310
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310
  + last=3311
  + a=3312
  + expr 3312 + 50
  + b=3362
  + c=3311
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310 -L3312:127.0.0.1:3362 -R3362:127.0.0.1:3311
  + last=3312
  + a=3320
  + expr 3320 + 50
  + b=3370
  + c=3312
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310 -L3312:127.0.0.1:3362 -R3362:127.0.0.1:3311 -L3320:127.0.0.1:3370 -R3370:127.0.0.1:3312
  + last=3320
  + a=3321
  + expr 3321 + 50
  + b=3371
  + c=3320
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310 -L3312:127.0.0.1:3362 -R3362:127.0.0.1:3311 -L3320:127.0.0.1:3370 -R3370:127.0.0.1:3312 -L3321:127.0.0.1:3371 -R3371:127.0.0.1:3320
  + last=3321
  + a=3322
  + expr 3322 + 50
  + b=3372
  + c=3321
  + fwd= -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310 -L3312:127.0.0.1:3362 -R3362:127.0.0.1:3311 -L3320:127.0.0.1:3370 -R3370:127.0.0.1:3312 -L3321:127.0.0.1:3371 -R3371:127.0.0.1:3320 -L3322:127.0.0.1:3372 -R3372:127.0.0.1:3321
  + last=3322
  + expr 3 - 2
  + q=1
  + ssh_version 1
  + echo 2
  + grep 1
  + q=2
  + trace start forwarding, fork to background
  + start_debug_log start forwarding, fork to background
  + echo trace: start forwarding, fork to background
  + echo trace: start forwarding, fork to background
  + echo trace: start forwarding, fork to background
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -f -L3300:127.0.0.1:3350 -R3350:127.0.0.1:4242 -L3301:127.0.0.1:3351 -R3351:127.0.0.1:3300 -L3302:127.0.0.1:3352 -R3352:127.0.0.1:3301 -L3310:127.0.0.1:3360 -R3360:127.0.0.1:3302 -L3311:127.0.0.1:3361 -R3361:127.0.0.1:3310 -L3312:127.0.0.1:3362 -R3362:127.0.0.1:3311 -L3320:127.0.0.1:3370 -R3370:127.0.0.1:3312 -L3321:127.0.0.1:3371 -R3371:127.0.0.1:3320 -L3322:127.0.0.1:3372 -R3372:127.0.0.1:3321 somehost sleep 10
  + trace transfer over forwarded channels and check result
  + start_debug_log transfer over forwarded channels and check result
  + echo trace: transfer over forwarded channels and check result
  + echo trace: transfer over forwarded channels and check result
  + echo trace: transfer over forwarded channels and check result
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -p3322 -o ConnectionAttempts=4 somehost cat /bin/ls
  + test -s /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + cmp /bin/ls /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + sleep 10
  + trace exit on -L forward failure, proto 2
  + start_debug_log exit on -L forward failure, proto 2
  + echo trace: exit on -L forward failure, proto 2
  + echo trace: exit on -L forward failure, proto 2
  + echo trace: exit on -L forward failure, proto 2
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -L 3301:127.0.0.1:4242 -L 3302:127.0.0.1:4242 -L 3303:127.0.0.1:4242 -L 3304:127.0.0.1:4242 -oExitOnForwardFailure=yes somehost true
  + [ 0 != 0 ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -q -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -L 3301:127.0.0.1:4242 -L 3302:127.0.0.1:4242 -L 3303:127.0.0.1:4242 -L 3301:localhost:4242 -L 3304:127.0.0.1:4242 -oExitOnForwardFailure=yes somehost true
  + r=255
  + [ 255 != 255 ]
  + trace exit on -R forward failure, proto 2
  + start_debug_log exit on -R forward failure, proto 2
  + echo trace: exit on -R forward failure, proto 2
  + echo trace: exit on -R forward failure, proto 2
  + echo trace: exit on -R forward failure, proto 2
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -R 3301:127.0.0.1:4242 -R 3302:127.0.0.1:4242 -R 3303:127.0.0.1:4242 -R 3304:127.0.0.1:4242 -oExitOnForwardFailure=yes somehost true
  + [ 0 != 0 ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -q -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -R 3301:127.0.0.1:4242 -R 3302:127.0.0.1:4242 -R 3303:127.0.0.1:4242 -R 3301:localhost:4242 -R 3304:127.0.0.1:4242 -oExitOnForwardFailure=yes somehost true
  + r=255
  + [ 255 != 255 ]
  + trace simple clear forwarding proto 2
  + start_debug_log simple clear forwarding proto 2
  + echo trace: simple clear forwarding proto 2
  + echo trace: simple clear forwarding proto 2
  + echo trace: simple clear forwarding proto 2
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -oClearAllForwardings=yes somehost true
  + trace clear local forward proto 2
  + start_debug_log clear local forward proto 2
  + echo trace: clear local forward proto 2
  + echo trace: clear local forward proto 2
  + echo trace: clear local forward proto 2
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -L 3301:127.0.0.1:4242 -oClearAllForwardings=yes somehost sleep 10
  + [ 0 != 0 ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -p 3301 true
  + sleep 10
  + trace clear remote forward proto 2
  + start_debug_log clear remote forward proto 2
  + echo trace: clear remote forward proto 2
  + echo trace: clear remote forward proto 2
  + echo trace: clear remote forward proto 2
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -R 3301:127.0.0.1:4242 -oClearAllForwardings=yes somehost sleep 10
  + [ 0 != 0 ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -p 3301 true
  + sleep 10
  + trace stdio forwarding proto 2
  + start_debug_log stdio forwarding proto 2
  + echo trace: stdio forwarding proto 2
  + echo trace: stdio forwarding proto 2
  + echo trace: stdio forwarding proto 2
  + [ X = Xyes ]
  + cmd=/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -o ProxyCommand /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -q -W localhost:4242 somehost somehost true
  + [ 0 != 0 ]
  + echo LocalForward 3301 127.0.0.1:4242
  + echo RemoteForward 3302 127.0.0.1:3301
  + trace config file: start forwarding, fork to background
  + start_debug_log config file: start forwarding, fork to background
  + echo trace: config file: start forwarding, fork to background
  + echo trace: config file: start forwarding, fork to background
  + echo trace: config file: start forwarding, fork to background
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -S /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ctl-sock -M -2 -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -f somehost sleep 10
  + trace config file: transfer over forwarded channels and check result
  + start_debug_log config file: transfer over forwarded channels and check result
  + echo trace: config file: transfer over forwarded channels and check result
  + echo trace: config file: transfer over forwarded channels and check result
  + echo trace: config file: transfer over forwarded channels and check result
  + [ X = Xyes ]
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -p3302 -o ConnectionAttempts=4 somehost cat /bin/ls
  + test -s /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + fail failed copy of /bin/ls
  + save_debug_log FAIL: failed copy of /bin/ls
  + echo FAIL: failed copy of /bin/ls
  + echo FAIL: failed copy of /bin/ls
  + echo FAIL: failed copy of /bin/ls
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/regress.log
  + echo
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh.log
  + echo
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd.log
  + echo
  + RESULT=1
  + echo failed copy of /bin/ls
  + cmp /bin/ls /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  failed copy of /bin/ls
  cmp: EOF on /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + fail corrupted copy of /bin/ls
  + save_debug_log FAIL: corrupted copy of /bin/ls
  + echo FAIL: corrupted copy of /bin/ls
  + echo FAIL: corrupted copy of /bin/ls
  + echo FAIL: corrupted copy of /bin/ls
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/regress.log
  + echo
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh.log
  + echo
  + cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/sshd.log
  + echo
  + RESULT=1
  + echo corrupted copy of /bin/ls
  + corrupted copy of /bin/ls
  /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -S /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ctl-sock -O exit somehost
  + trace transfer over chained unix domain socket forwards and check result
  + start_debug_log transfer over chained unix domain socket forwards and check result
  + echo trace: transfer over chained unix domain socket forwards and check result
  + echo trace: transfer over chained unix domain socket forwards and check result
  + echo trace: transfer over chained unix domain socket forwards and check result
  + [ X = Xyes ]
  + rm -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-[123].fwd
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -R3301:[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-1.fwd] somehost sleep 10
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -L[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-1.fwd]:[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-2.fwd] somehost sleep 10
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -R[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-2.fwd]:[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-3.fwd] somehost sleep 10
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -f -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -L[/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/unix-3.fwd]:127.0.0.1:4242 somehost sleep 10
  + /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh-log-wrapper.sh -F /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/ssh_config -p3301 -o ConnectionAttempts=4 somehost cat /bin/ls
  + test -s /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + cmp /bin/ls /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/copy
  + sleep 10
  + cleanup
  + [ x != x ]
  + stop_sshd
  + [ -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile ]
  + sudo cat /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile
  + pid=32570
  + [ X32570 = X ]
  + [ 32570 -lt 2 ]
  + sudo kill 32570
  + trace wait for sshd to exit
  + start_debug_log wait for sshd to exit
  + echo trace: wait for sshd to exit
  + echo trace: wait for sshd to exit
  + echo trace: wait for sshd to exit
  + [ X = Xyes ]
  + i=0
  + [ -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile -a 0 -lt 5 ]
  + test -f /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/pidfile
  + [ 1 -eq 0 ]
  + echo failed local and remote forwarding
  + exit 1
  failed local and remote forwarding
  Makefile:199: recipe for target 't-exec' failed
  make: Leaving directory '/tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress'
  make: *** [t-exec] Error 1
  ==> /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/failed-regress.log <==
  trace: config file: transfer over forwarded channels and check result
  FAIL: failed copy of /bin/ls
  
  trace: config file: transfer over forwarded channels and check result
  FAIL: failed copy of /bin/ls
  FAIL: corrupted copy of /bin/ls
  
  ==> /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/failed-ssh.log <==
  trace: config file: transfer over forwarded channels and check result
  debug2: resolving "127.0.0.1" port 3302
  debug2: ssh_connect_direct: needpriv 0
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  ssh: connect to host 127.0.0.1 port 3302: Connection refused
  FAIL: failed copy of /bin/ls
  
  trace: config file: transfer over forwarded channels and check result
  debug2: resolving "127.0.0.1" port 3302
  debug2: ssh_connect_direct: needpriv 0
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  debug1: Trying again...
  debug1: Connecting to 127.0.0.1 [127.0.0.1] port 3302.
  debug1: connect to address 127.0.0.1 port 3302: Connection refused
  ssh: connect to host 127.0.0.1 port 3302: Connection refused
  FAIL: failed copy of /bin/ls
  FAIL: corrupted copy of /bin/ls
  
  ==> /tmp/autopkgtest-virt-lxc.shared.hhquaatj/downtmp/autopkgtest_tmp/user/tree/regress/failed-sshd.log <==
  trace: config file: transfer over forwarded channels and check result
  dWCUHL3hrO9Sb+pyo0ZTZvaU
  debug3: notify_hostkeys: sent 2 hostkeys
  debug3: send packet: type 80
  debug1: Entering interactive session for SSH2.
  debug2: fd 7 setting O_NONBLOCK
  debug2: fd 8 setting O_NONBLOCK
  debug1: server_init_dispatch
  debug3: receive packet: type 80
  debug1: server_input_global_request: rtype tcpip-forward want_reply 1
  debug1: server_input_global_request: tcpip-forward listen localhost port 3302
  debug3: channel_setup_fwd_listener_tcpip: type 11 wildcard 0 addr NULL
  debug1: Local forwarding listening on 127.0.0.1 port 3302.
  debug2: fd 9 setting O_NONBLOCK
  debug3: fd 9 is O_NONBLOCK
  debug1: channel 0: new [port listener]
  debug3: send packet: type 81
  packet_write_wait: Connection from 127.0.0.1 port 60879: Broken pipe
  debug1: do_cleanup
  debug3: mm_request_receive entering
  debug1: do_cleanup
  debug1: audit_event: unhandled event 12
  FAIL: failed copy of /bin/ls
  
  trace: config file: transfer over forwarded channels and check result
  dWCUHL3hrO9Sb+pyo0ZTZvaU
  debug3: notify_hostkeys: sent 2 hostkeys
  debug3: send packet: type 80
  debug1: Entering interactive session for SSH2.
  debug2: fd 7 setting O_NONBLOCK
  debug2: fd 8 setting O_NONBLOCK
  debug1: server_init_dispatch
  debug3: receive packet: type 80
  debug1: server_input_global_request: rtype tcpip-forward want_reply 1
  debug1: server_input_global_request: tcpip-forward listen localhost port 3302
  debug3: channel_setup_fwd_listener_tcpip: type 11 wildcard 0 addr NULL
  debug1: Local forwarding listening on 127.0.0.1 port 3302.
  debug2: fd 9 setting O_NONBLOCK
  debug3: fd 9 is O_NONBLOCK
  debug1: channel 0: new [port listener]
  debug3: send packet: type 81
  packet_write_wait: Connection from 127.0.0.1 port 60879: Broken pipe
  debug1: do_cleanup
  debug3: mm_request_receive entering
  debug1: do_cleanup
  debug1: audit_event: unhandled event 12
  FAIL: failed copy of /bin/ls
  FAIL: corrupted copy of /bin/ls

Full output here:

  https://ci.debian.net/data/packages/unstable/amd64/o/openssh/20161231_044927.autopkgtest.log.gz
  https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-zesty/zesty/s390x/o/openssh/20161231_120523_ebc8a@/log.gz

Thanks,

-- 
Colin Watson                                       [cjwatson at debian.org]


More information about the openssh-unix-dev mailing list