Attachment 3492 Details for Bug 3290 – client logs with ControlPersist

client logs with ControlPersist

ssh-with-controlpersist.txt (text/plain), 16.30 KB, created by Richard Schwab on 2021-03-30 09:33:40 AEDT

(hide)

Description:

Filename:

MIME Type:

Creator: Richard Schwab

Created: 2021-03-30 09:33:40 AEDT

Size: 16.30 KB

patch

obsolete

>[sshtest@merga ~]$ ssh -F /dev/null -vvv -N -o ControlMaster=auto -o ControlPath=~/cptest -o ControlPersist=5 localhost
>OpenSSH_8.5p1, OpenSSL 1.1.1k  25 Mar 2021
>debug1: Reading configuration data /dev/null
>debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> '/home/sshtest/.ssh/known_hosts'
>debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> '/home/sshtest/.ssh/known_hosts2'
>debug1: auto-mux: Trying existing master
>debug1: Control socket "/home/sshtest/cptest" does not exist
>debug2: resolving "localhost" port 22
>debug3: ssh_connect_direct: entering
>debug1: Connecting to localhost [::1] port 22.
>debug3: set_sock_tos: set socket 3 IPV6_TCLASS 0x48
>debug1: Connection established.
>debug1: identity file /home/sshtest/.ssh/id_rsa type -1
>debug1: identity file /home/sshtest/.ssh/id_rsa-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_dsa type -1
>debug1: identity file /home/sshtest/.ssh/id_dsa-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_ecdsa type -1
>debug1: identity file /home/sshtest/.ssh/id_ecdsa-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_ecdsa_sk type -1
>debug1: identity file /home/sshtest/.ssh/id_ecdsa_sk-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_ed25519 type 3
>debug1: identity file /home/sshtest/.ssh/id_ed25519-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_ed25519_sk type -1
>debug1: identity file /home/sshtest/.ssh/id_ed25519_sk-cert type -1
>debug1: identity file /home/sshtest/.ssh/id_xmss type -1
>debug1: identity file /home/sshtest/.ssh/id_xmss-cert type -1
>debug1: Local version string SSH-2.0-OpenSSH_8.5
>debug1: Remote protocol version 2.0, remote software version OpenSSH_8.5
>debug1: compat_banner: match: OpenSSH_8.5 pat OpenSSH* compat 0x04000000
>debug2: fd 3 setting O_NONBLOCK
>debug1: Authenticating to localhost:22 as 'sshtest'
>debug3: record_hostkey: found key type ED25519 in file /home/sshtest/.ssh/known_hosts:1
>debug3: record_hostkey: found key type RSA in file /home/sshtest/.ssh/known_hosts:2
>debug3: record_hostkey: found key type ECDSA in file /home/sshtest/.ssh/known_hosts:3
>debug3: load_hostkeys_file: loaded 3 keys from localhost
>debug1: load_hostkeys: fopen /home/sshtest/.ssh/known_hosts2: No such file or directory
>debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
>debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
>debug3: order_hostkeyalgs: have matching best-preference key type ssh-ed25519-cert-v01@openssh.com, using HostkeyAlgorithms verbatim
>debug3: send packet: type 20
>debug1: SSH2_MSG_KEXINIT sent
>debug3: receive packet: type 20
>debug1: SSH2_MSG_KEXINIT received
>debug2: local client KEXINIT proposal
>debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c
>debug2: host key algorithms: ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
>debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
>debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
>debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
>debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
>debug2: compression ctos: none,zlib@openssh.com,zlib
>debug2: compression stoc: none,zlib@openssh.com,zlib
>debug2: languages ctos:
>debug2: languages stoc:
>debug2: first_kex_follows 0
>debug2: reserved 0
>debug2: peer server KEXINIT proposal
>debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256
>debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
>debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
>debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
>debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
>debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
>debug2: compression ctos: none,zlib@openssh.com
>debug2: compression stoc: none,zlib@openssh.com
>debug2: languages ctos:
>debug2: languages stoc:
>debug2: first_kex_follows 0
>debug2: reserved 0
>debug1: kex: algorithm: curve25519-sha256
>debug1: kex: host key algorithm: ssh-ed25519
>debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
>debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
>debug3: send packet: type 30
>debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
>debug3: receive packet: type 31
>debug1: SSH2_MSG_KEX_ECDH_REPLY received
>debug1: Server host key: ssh-ed25519 SHA256:NdU2JDzk3Zvq1RSY62LYGZd5eXrwr7cbt9eR4M1Q83U
>debug3: record_hostkey: found key type ED25519 in file /home/sshtest/.ssh/known_hosts:1
>debug3: record_hostkey: found key type RSA in file /home/sshtest/.ssh/known_hosts:2
>debug3: record_hostkey: found key type ECDSA in file /home/sshtest/.ssh/known_hosts:3
>debug3: load_hostkeys_file: loaded 3 keys from localhost
>debug1: load_hostkeys: fopen /home/sshtest/.ssh/known_hosts2: No such file or directory
>debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
>debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
>debug1: Host 'localhost' is known and matches the ED25519 host key.
>debug1: Found key in /home/sshtest/.ssh/known_hosts:1
>debug3: send packet: type 21
>debug2: set_newkeys: mode 1
>debug1: rekey out after 134217728 blocks
>debug1: SSH2_MSG_NEWKEYS sent
>debug1: expecting SSH2_MSG_NEWKEYS
>debug3: receive packet: type 21
>debug1: SSH2_MSG_NEWKEYS received
>debug2: set_newkeys: mode 0
>debug1: rekey in after 134217728 blocks
>debug1: Will attempt key: /home/sshtest/.ssh/id_rsa
>debug1: Will attempt key: /home/sshtest/.ssh/id_dsa
>debug1: Will attempt key: /home/sshtest/.ssh/id_ecdsa
>debug1: Will attempt key: /home/sshtest/.ssh/id_ecdsa_sk
>debug1: Will attempt key: /home/sshtest/.ssh/id_ed25519 ED25519 SHA256:cmbYHSR/YDz6Bkut7ikaxfqCZZsQSQVBOo38Hf35M8k
>debug1: Will attempt key: /home/sshtest/.ssh/id_ed25519_sk
>debug1: Will attempt key: /home/sshtest/.ssh/id_xmss
>debug2: pubkey_prepare: done
>debug3: send packet: type 5
>debug3: receive packet: type 7
>debug1: SSH2_MSG_EXT_INFO received
>debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,sk-ssh-ed25519@openssh.com,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,webauthn-sk-ecdsa-sha2-nistp256@openssh.com>
>debug3: receive packet: type 6
>debug2: service_accept: ssh-userauth
>debug1: SSH2_MSG_SERVICE_ACCEPT received
>debug3: send packet: type 50
>debug3: receive packet: type 51
>debug1: Authentications that can continue: publickey,password
>debug3: start over, passed a different list publickey,password
>debug3: preferred publickey,keyboard-interactive,password
>debug3: authmethod_lookup publickey
>debug3: remaining preferred: keyboard-interactive,password
>debug3: authmethod_is_enabled publickey
>debug1: Next authentication method: publickey
>debug1: Trying private key: /home/sshtest/.ssh/id_rsa
>debug3: no such identity: /home/sshtest/.ssh/id_rsa: No such file or directory
>debug1: Trying private key: /home/sshtest/.ssh/id_dsa
>debug3: no such identity: /home/sshtest/.ssh/id_dsa: No such file or directory
>debug1: Trying private key: /home/sshtest/.ssh/id_ecdsa
>debug3: no such identity: /home/sshtest/.ssh/id_ecdsa: No such file or directory
>debug1: Trying private key: /home/sshtest/.ssh/id_ecdsa_sk
>debug3: no such identity: /home/sshtest/.ssh/id_ecdsa_sk: No such file or directory
>debug1: Offering public key: /home/sshtest/.ssh/id_ed25519 ED25519 SHA256:cmbYHSR/YDz6Bkut7ikaxfqCZZsQSQVBOo38Hf35M8k
>debug3: send packet: type 50
>debug2: we sent a publickey packet, wait for reply
>debug3: receive packet: type 60
>debug1: Server accepts key: /home/sshtest/.ssh/id_ed25519 ED25519 SHA256:cmbYHSR/YDz6Bkut7ikaxfqCZZsQSQVBOo38Hf35M8k
>debug3: sign_and_send_pubkey: ED25519 SHA256:cmbYHSR/YDz6Bkut7ikaxfqCZZsQSQVBOo38Hf35M8k
>debug3: sign_and_send_pubkey: signing using ssh-ed25519 SHA256:cmbYHSR/YDz6Bkut7ikaxfqCZZsQSQVBOo38Hf35M8k
>debug3: send packet: type 50
>debug3: receive packet: type 52
>debug1: Authentication succeeded (publickey).
>Authenticated to localhost ([::1]:22).
>debug1: setting up multiplex master socket
>debug3: muxserver_listen: temporary control path /home/sshtest/cptest.exxN0wlQ30TE9fgQ
>debug2: fd 4 setting O_NONBLOCK
>debug3: fd 4 is O_NONBLOCK
>debug3: fd 4 is O_NONBLOCK
>debug1: channel 0: new [/home/sshtest/cptest]
>debug3: muxserver_listen: mux listener channel 0 fd 4
>debug2: fd 3 setting TCP_NODELAY
>debug3: set_sock_tos: set socket 3 IPV6_TCLASS 0x20
>debug1: control_persist_detach: backgrounding master process
>debug2: control_persist_detach: background process is 1000851
>debug2: fd 4 setting O_NONBLOCK
>debug1: forking to background
>debug1: Entering interactive session.
>debug1: pledge: id
>debug2: set_control_persist_exit_time: schedule exit in 5 seconds
>debug1: multiplexing control connection
>debug2: fd 5 setting O_NONBLOCK
>debug3: fd 5 is O_NONBLOCK
>debug1: channel 1: new [mux-control]
>debug3: channel_post_mux_listener: new mux channel 1 fd 5
>debug3: mux_master_read_cb: channel 1: hello sent
>debug2: set_control_persist_exit_time: cancel scheduled exit
>debug3: mux_master_read_cb: channel 1 packet type 0x00000001 len 4
>debug2: mux_master_process_hello: channel 1 client version 4
>debug2: mux_client_hello_exchange: master version 4
>debug3: mux_client_forwards: request forwardings: 0 local, 0 remote
>debug3: mux_client_request_session: entering
>debug3: mux_client_request_alive: entering
>debug3: mux_master_read_cb: channel 1 packet type 0x10000004 len 4
>debug2: mux_master_process_alive_check: channel 1: alive check
>debug3: mux_client_request_alive: done pid = 1000854
>debug3: mux_client_request_session: session request sent
>debug3: mux_master_read_cb: channel 1 packet type 0x10000002 len 50
>debug2: mux_master_process_new_session: channel 1: request tty 0, X 0, agent 0, subsys 0, term "xterm-256color", cmd "", env 0
>debug3: mux_master_process_new_session: got fds stdin 6, stdout 7, stderr 8
>debug1: channel 2: new [client-session]
>debug2: mux_master_process_new_session: channel_new: 2 linked to control channel 1
>debug2: channel 2: send open
>debug3: send packet: type 90
>debug3: receive packet: type 80
>debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
>debug3: client_input_hostkeys: received RSA key SHA256:DGvHWMpFaHiVC6KUZ1XbXGH8IyGwA2ZCkFWZWygdJxg
>debug3: client_input_hostkeys: received ECDSA key SHA256:RVLSCt5ruolRyIt7/tZ4KaIH9oRWfJ599X8Vwc6izjk
>debug3: client_input_hostkeys: received ED25519 key SHA256:NdU2JDzk3Zvq1RSY62LYGZd5eXrwr7cbt9eR4M1Q83U
>debug1: client_input_hostkeys: searching /home/sshtest/.ssh/known_hosts for localhost / (none)
>debug3: hostkeys_foreach: reading file "/home/sshtest/.ssh/known_hosts"
>debug3: hostkeys_find: found ssh-ed25519 key at /home/sshtest/.ssh/known_hosts:1
>debug3: hostkeys_find: found ssh-rsa key at /home/sshtest/.ssh/known_hosts:2
>debug3: hostkeys_find: found ecdsa-sha2-nistp256 key at /home/sshtest/.ssh/known_hosts:3
>debug1: client_input_hostkeys: searching /home/sshtest/.ssh/known_hosts2 for localhost / (none)
>debug1: client_input_hostkeys: hostkeys file /home/sshtest/.ssh/known_hosts2 does not exist
>debug3: client_input_hostkeys: 3 server keys: 0 new, 3 retained, 0 incomplete match. 0 to remove
>debug1: client_input_hostkeys: no new or deprecated keys from server
>debug3: receive packet: type 4
>debug1: Remote: /home/sshtest/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
>debug3: receive packet: type 4
>debug1: Remote: /home/sshtest/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
>debug3: receive packet: type 91
>debug2: channel_input_open_confirmation: channel 2: callback start
>debug2: client_session2_setup: id 2
>debug2: channel 2: request shell confirm 1
>debug3: send packet: type 98
>debug3: mux_session_confirm: sending success reply
>debug2: channel_input_open_confirmation: channel 2: callback done
>debug2: channel 2: open confirm rwindow 0 rmax 32768
>debug1: mux_client_request_session: master session id: 2
>debug2: channel 2: rcvd adjust 2097152
>debug3: receive packet: type 99
>debug2: channel_input_status_confirm: type 99 id 2
>debug2: shell request accepted on channel 2
>debug3: receive packet: type 96
>debug2: channel 2: rcvd eof
>debug2: channel 2: output open -> drain
>This is not a real shell, you are not supposed to login.
>debug3: receive packet: type 98
>debug1: client_input_channel_req: channel 2 rtype exit-status reply 0
>debug3: mux_exit_message: channel 2: exit message, exitval 0
>debug3: receive packet: type 98
>debug1: client_input_channel_req: channel 2 rtype eow@openssh.com reply 0
>debug2: channel 2: rcvd eow
>debug2: chan_shutdown_read: channel 2: (i0 o1 sock -1 wfd 6 efd 8 [write])
>debug2: channel 2: input open -> closed
>debug3: receive packet: type 97
>debug2: channel 2: rcvd close
>debug3: channel 2: will not send data after close
>debug2: channel 2: obuf empty
>debug2: chan_shutdown_write: channel 2: (i3 o1 sock -1 wfd 7 efd 8 [write])
>debug2: channel 2: output drain -> closed
>debug2: channel 2: send close
>debug3: send packet: type 97
>debug2: channel 2: is dead
>debug2: channel 2: gc: notify user
>debug3: mux_master_session_cleanup_cb: entering for channel 2
>debug2: channel 1: rcvd close
>debug2: channel 1: output open -> drain
>debug2: chan_shutdown_read: channel 1: (i0 o1 sock 5 wfd 5 efd -1 [closed])
>debug2: channel 1: input open -> closed
>debug2: channel 2: gc: user detached
>debug2: channel 2: is dead
>debug2: channel 2: garbage collecting
>debug1: channel 2: free: client-session, nchannels 3
>debug3: channel 2: status: The following connections are open:
>  #1 mux-control (t16 nr0 i3/0 o1/16 e[closed]/0 fd 5/5/-1 sock 5 cc -1)
>  #2 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/8 sock -1 cc -1)
>
>debug2: channel 1: obuf empty
>debug2: chan_shutdown_write: channel 1: (i3 o1 sock 5 wfd 5 efd -1 [closed])
>debug2: channel 1: output drain -> closed
>debug2: channel 1: is dead (local)
>debug2: channel 1: gc: notify user
>debug3: mux_client_read_packet: read header failed: Broken pipe
>debug2: Received exit status from master 0
>debug3: mux_master_control_cleanup_cb: entering for channel 1
>debug2: channel 1: gc: user detached
>debug2: channel 1: is dead (local)
>debug2: channel 1: garbage collecting
>debug1: channel 1: free: mux-control, nchannels 2
>debug3: channel 1: status: The following connections are open:
>  #1 mux-control (t16 nr0 i3/0 o3/0 e[closed]/0 fd 5/5/-1 sock 5 cc -1)
>
>debug2: set_control_persist_exit_time: schedule exit in 5 seconds
>[sshtest@merga ~]$ debug1: ControlPersist timeout expired
>debug3: send packet: type 1
>debug1: channel 0: free: /home/sshtest/cptest, nchannels 1
>debug3: channel 0: status: The following connections are open:
>
>debug3: fd 0 is not O_NONBLOCK
>debug3: fd 1 is not O_NONBLOCK
>Transferred: sent 2120, received 2688 bytes, in 5.2 seconds
>Bytes per second: sent 408.4, received 517.8
>debug1: Exit status -1

Actions: View

Attachments on bug 3290: 3490 | 3491 | 3492 | 3493 | 3512