[Regression] OpenSSH 7.7p1 no longer tests on NonStop Port (long)

Fri Feb 1 21:36:35 AEDT 2019

On January 30, 2019 17:08, Darren Tucker wrote:
> On Thu, 31 Jan 2019 at 07:50, Randall S. Becker <rsbecker at nexbridge.com>
> wrote:
> > Is there any way to bypass this one failing test and carry blindly
forward?
> > I think this key has had issues in the past that we just did not see.
> 
> "make -k tests" if you don't care about the final return code.  If you do
care
> about the final return code, remove the problematic test from the LTESTS
> variable in regress/Makefile.

Just to keep people in the loop, here is a complete list of the tests that
fail on NonStop. Obviously we have to dig deeper into this and figure out
why there is an issue on this particular platform (IA64 Big Endian). I am
suspicious that we may have lost some changes through merges because the
modpipe problem looks familiar. More investigation is required.

FWIW, make -k does not work for us (gnu make 4.1). We had to edit
regress/Makefile inhibiting the exit.

The logs are slightly annotated where things were making sense.

Sorry about the length of this.
Randall

run test key-options.sh ...
key option command="echo bar"
key option no-pty,command="echo bar"
key option pty default
key option failed default
exit 1

Very little in regress/failed-regress.log or regress/failed-regress.ssh
trace: key option pty default
FAIL: key option failed default

****************************************

run test cert-userkey.sh ...
<snip>
certified user keys: ensure CA key does not authenticate user
certified user keys: correct principal auth authorized_keys expect success
rsa
certified user keys: correct principal auth authorized_keys expect success
ed25519
certified user keys: correct principal auth TrustedUserCAKeys expect success
rsa
certified user keys: correct principal auth TrustedUserCAKeys expect success
ed25519
correct principal failed unexpectedly
exit 1

the ssh log for this had more info:

debug2: input_userauth_pk_ok: fp
SHA256:nQt9ANYAY/Vjv5Z/g4Y1jGNlpnM2FlrtuS5k2o/iLXc
debug3: sign_and_send_pubkey: ED25519-CERT
SHA256:nQt9ANYAY/Vjv5Z/g4Y1jGNlpnM2FlrtuS5k2o/iLXc
debug2: sign_and_send_pubkey: using private key
"/home/git/openssh-portable/regress/cert_user_key_ed25519" for certificate
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to 127.0.0.1 (via proxy).
debug2: fd 7 setting O_NONBLOCK
debug3: fd 8 is O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting no-more-sessions at openssh.com
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: proc
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00 at openssh.com
want_reply 0
debug3: receive packet: type 4
debug1: Remote: cert: key options: agent-forwarding port-forwarding pty
user-rc x11-forwarding
debug3: receive packet: type 4
debug1: Remote: cert: key options: agent-forwarding port-forwarding pty
user-rc x11-forwarding
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: client_session2_setup: id 0
debug1: Sending command: true
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: client_input_channel_req: exit-status set to 255 at 1723
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype eow at openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)

debug3: send packet: type 1
debug3: fd 1 is not O_NONBLOCK
debug1: fd 2 clearing O_NONBLOCK
Transferred: sent 3856, received 3288 bytes, in 0.0 seconds
Bytes per second: sent 198908.3, received 169608.6
debug1: Exit status 255
FAIL: correct principal failed unexpectedly

And failed-sshd.log looks suspect:

debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max
32768
debug1: input_session_request
debug1: channel 0: new [server-session]
debug2: session_new: allocate (allocated 0 max 10)
debug3: session_unused: session id 0 unused
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug3: send packet: type 91
debug3: receive packet: type 80
debug1: server_input_global_request: rtype no-more-sessions at openssh.com
want_reply 0
debug3: receive packet: type 98
debug1: server_input_channel_req: channel 0 request exec reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req exec
Starting session: command for randall from UNKNOWN port 65535 id 0
debug3: do_exec_no_pty: executing
debug3: do_exec_no_pty: initiating fork()
debug2: fd 10 setting O_NONBLOCK
debug2: fd 9 setting O_NONBLOCK
debug2: fd 12 setting O_NONBLOCK
debug3: do_exec_no_pty: fork() in child
debug3: send packet: type 99
debug3: do_child: entering do_child()
debug1: permanently_set_uid: XXXXXXXXXX (masked for security)
permanently_set_uid: was able to restore old [e]uid
debug1: do_cleanup
debug2: channel 0: read 0 from efd 12
debug2: channel 0: closing read-efd 12
debug2: channel 0: read<=0 rfd 10 len 0
debug2: channel 0: read failed
debug2: channel 0: close_read
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug1: Received SIGCHLD.
debug3: collect_children: received pid 2130706452 with errno 4004 (EINTR)
debug1: session_by_pid: pid 2130706452
debug3: session_exit_message: status: 65280
debug1: session_exit_message: session 0 channel 0 pid 2130706452
debug2: channel 0: request exit-status confirm 0
debug3: send packet: type 98
debug1: session_exit_message: release channel 0
debug2: channel 0: write failed
debug2: channel 0: close_write
debug2: channel 0: send eow
debug3: send packet: type 98
debug2: channel 0: output open -> closed
debug3: collect_children: while exit received pid -1 with errno 4010
(ECHILD)
debug2: channel 0: send close
debug3: send packet: type 97
debug3: channel 0: will not send data after close
debug2: notify_done: reading
debug3: channel 0: will not send data after close
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: is dead
debug2: channel 0: gc: notify user
debug1: session_by_channel: session 0 channel 0
debug1: session_close_by_channel: channel 0 child 0
Close session: user randall from UNKNOWN port 65535 id 0
debug3: session_unused: session id 0 unused
debug2: channel 0: gc: user detached
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: server-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 server-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)

debug3: receive packet: type 1
Received disconnect from UNKNOWN port 65535:11: disconnected by user
Disconnected from user randall UNKNOWN port 65535
debug1: do_cleanup
FAIL: correct principal failed unexpectedly

cat regress/failed-regress.log
trace: certified user keys: correct principal auth TrustedUserCAKeys expect
success ed25519
FAIL: correct principal failed unexpectedly

****************************************

run test integrity.sh ...
test integrity: hmac-sha1 @2900
modpipe: warning - mod unexpected error mac hmac-sha1 at 2900: Transferred:
sent 2088, received 2392 bytes, in 0.1 seconds.Bytes per second: sent
41387.6, received 47413.4.
exit 1

cat regress/failed-regress.log
trace: test integrity: hmac-sha1 @2900
FAIL: unexpected error mac hmac-sha1 at 2900: Transferred: sent 2088,
received 2392 bytes, in 0.1 seconds.Bytes per second: sent 28464.7, received
32609.0.

cat regress/failed-ssh.log
<snip>
Authenticated to 127.0.0.1 (via proxy).
debug2: fd 7 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting no-more-sessions at openssh.com
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: proc
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00 at openssh.com
want_reply 0
debug3: receive packet: type 4
debug1: Remote:
/home/git/openssh-portable/regress/authorized_keys_randall:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 4
debug1: Remote:
/home/git/openssh-portable/regress/authorized_keys_randall:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: client_session2_setup: id 0
debug1: Sending command: printf "%4096s" " "
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-signal reply 0
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype eow at openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)

debug3: send packet: type 1
debug3: fd 1 is not O_NONBLOCK
Transferred: sent 2088, received 2392 bytes, in 0.1 seconds
Bytes per second: sent 28464.7, received 32609.0
debug1: Exit status -1
FAIL: unexpected error mac hmac-sha1 at 2900: Transferred: sent 2088,
received 2392 bytes, in 0.1 seconds.Bytes per second: sent 28464.7, received
32609.0.

cat regress/failed-sshd.log
Starting session: command for randall from UNKNOWN port 65535 id 0
debug3: do_exec_no_pty: executing
debug3: do_exec_no_pty: initiating fork()
debug2: fd 10 setting O_NONBLOCK
debug2: fd 9 setting O_NONBLOCK
debug2: fd 12 setting O_NONBLOCK
debug3: do_exec_no_pty: fork() in child
debug3: send packet: type 99
debug3: do_child: entering do_child()
debug1: permanently_set_uid: XXXXXXXXX (masked for security)
debug3: do_child: Shell path=/bin/ksh
debug2: channel 0: read 0 from efd 12
debug2: channel 0: closing read-efd 12
debug2: channel 0: read<=0 rfd 10 len 0
debug2: channel 0: read failed
debug2: channel 0: close_read
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug1: Received SIGCHLD.
debug3: collect_children: received pid 671088721 with errno 4004 (EINTR)
debug1: session_by_pid: pid 671088721
debug3: session_exit_message: status: -2130707957 (This does not look
correct)
debug1: session_exit_message: session 0 channel 0 pid 671088721
debug2: channel 0: request exit-signal confirm 0
debug3: send packet: type 98
debug1: session_exit_message: release channel 0
debug2: channel 0: write failed
debug2: channel 0: close_write
debug2: channel 0: send eow
debug3: send packet: type 98
debug2: channel 0: output open -> closed
debug3: collect_children: while exit received pid -1 with errno 4010
(ECHILD)
debug2: channel 0: send close
debug3: send packet: type 97
debug3: channel 0: will not send data after close
debug2: notify_done: reading
debug3: channel 0: will not send data after close
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: receive packet: type 1
Received disconnect from UNKNOWN port 65535:11: disconnected by user
Disconnected from user randall UNKNOWN port 65535
debug1: do_cleanup
FAIL: unexpected error mac hmac-sha1 at 2900: Transferred: sent 2088,
received 2392 bytes, in 0.1 seconds.Bytes per second: sent 28464.7, received
32609.0.