SFTP connection fails for wodSSH clients
jtesta opened this issue · 2 comments
The following SFTP session fails with the "WeOnlyDo 3.7.3.170" client (which is perhaps this software). While this isn't very common client software, debugging this issue may fix other related problems.
Sep 5 12:17:26 ubuntu1804lts sshd_mitm[11878]: Server listening on :: port 2222.
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[11878]: debug3: fd 5 is not O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[11878]: debug1: Forked child 12030.
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[11878]: debug3: send_rexec_state: entering fd = 8 config len 344
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[11878]: debug3: ssh_msg_send: type 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: oom_adjust_restore
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[11878]: debug3: send_rexec_state: done
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: Set /proc/self/oom_score_adj to 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: inetd sockets after dupping: 3, 3
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: Connection from 172.16.x.x port 52818 on 172.23.63.215 port 2222
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: Client protocol version 2.0; client software version WeOnlyDo 3.7.3.170
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: no match: WeOnlyDo 3.7.3.170
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: Local version string SSH-2.0-OpenSSH_7.5
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: Enabling compatibility mode for protocol 2.0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: fd 3 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: Network child is on pid 12031
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: preauth child monitor started
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-ed25519 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 20 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 20 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: SSH2_MSG_KEXINIT received [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: local server KEXINIT proposal [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: 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,diffie-hellman-group14-sha1 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-ed25519 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: 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 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: 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 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: compression ctos: none,zlib@openssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: compression stoc: none,zlib@openssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: languages ctos: [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: languages stoc: [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: first_kex_follows 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: reserved 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: peer client KEXINIT proposal [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: KEX algorithms: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group1-sha1,diffie-hellman-group14-sha1 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: host key algorithms: ssh-rsa,ssh-dss,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: ciphers ctos: aes192-cbc,aes192-ctr,3des-cbc,blowfish-cbc,aes128-cbc,aes128-ctr,aes256-cbc,aes256-ctr,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc@lysator.liu.se,des-cbc,des-cbc@ssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: ciphers stoc: aes192-cbc,aes192-ctr,3des-cbc,blowfish-cbc,aes128-cbc,aes128-ctr,aes256-cbc,aes256-ctr,rijndael128-cbc,rijn:dael192-cbc,rijndael256-cbc,rijndael-cbc@lysator.liu.se,des-cbc,des-cbc@ssh.com [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: MACs ctos: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: MACs stoc: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: compression ctos: none,none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: compression stoc: none,none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: languages ctos: [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: languages stoc: [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: first_kex_follows 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: reserved 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: kex: algorithm: ecdh-sha2-nistp256 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: kex: host key algorithm: ssh-rsa [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: kex: client->server cipher: aes192-ctr MAC: hmac-sha2-256 compression: none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: kex: server->client cipher: aes192-ctr MAC: hmac-sha2-256 compression: none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 30 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_key_sign entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 6 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive_expect entering: type 7 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: monitor_read: checking request 6
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_sign
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_sign: hostkey proof signature 0x55bcd7827ca0(527)
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 7
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: monitor_read: 6 used once, disabling now
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 31 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 21 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: set_newkeys: mode 1 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: rekey after 4294967296 blocks [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 21 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: set_newkeys: mode 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: rekey after 4294967296 blocks [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: KEX done [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 5 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 6 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 50 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: userauth-request for user ssh-mitm service ssh-connection method none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: attempt 0 failures 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_getpwnamallow entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 8 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive_expect entering: type 9 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: monitor_read: checking request 8
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_pwnamallow
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: parse_server_config: config reprocess config len 344
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 9
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: monitor_read: 8 used once, disabling now
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: input_userauth_request: setting up authctxt for ssh-mitm [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_inform_authserv entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 4 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: input_userauth_request: try method none [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 51 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: receive packet: type 50 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: userauth-request for user ssh-mitm service ssh-connection method password [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: attempt 1 failures 0 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: input_userauth_request: try method password [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: INTERCEPTED PASSWORD: hostname: [10.x.x.x]; username: [sftpuser]; password: [*************] [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_auth_password entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 12 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive_expect entering: type 13 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: monitor_read: checking request 4
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_authserv: service=ssh-connection, style=
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug2: monitor_read: 4 used once, disabling now
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: monitor_read: checking request 12
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_authpassword: sending result 1
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 13
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: Accepted password for ssh-mitm from 172.16.x.x port 52818 ssh2
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: monitor_child_preauth: ssh-mitm has been authenticated by privileged process
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_get_keystate: Waiting for new keys
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive_expect entering: type 26
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_get_keystate: GOT new keys
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_get_lol: Waiting for lol
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive_expect entering: type 52
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_get_lol: GOT lol
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_auth_password: user authenticated [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: send packet: type 52 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 26 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_send_keystate: Finished sending state [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: SENDING lol [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_send entering: type 52 [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug3: mm_send_lol: Finished sending lol [preauth]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: debug1: monitor_read_log: child log fd closed
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12030]: User child is on pid 12033
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: monitor_apply_keystate: packet_set_state
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: set_newkeys: mode 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: rekey after 4294967296 blocks
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: set_newkeys: mode 1
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: rekey after 4294967296 blocks
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: ssh_packet_set_postauth: called
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: ssh_packet_set_state: done
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: Applying lol...
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: Done with lol...
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: notify_hostkeys: key 0: ssh-rsa SHA256:4U6J921L//RAUaxBF3db9LnLVxkb8pKhRX9pwCVK42Q
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: notify_hostkeys: key 1: ssh-ed25519 SHA256:Rt0bz04nxWHR72RWqaqhPcZRlGAJ/f4E4gGPFZthFf8
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: notify_hostkeys: sent 2 hostkeys
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: send packet: type 80
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: Entering interactive session for SSH2.
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 5 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 6 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: server_init_dispatch
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: receive packet: type 90
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: server_input_channel_open: ctype session rchan 0 win 524288 max 32768
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: input_session_request
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: channel 0: new [server-session]
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: session_new: allocate (allocated 0 max 10)
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: session_unused: session id 0 unused
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: session_new: session 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: session_open: channel 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: session_open: session 0: link with channel 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: server_input_channel_open: confirm session
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: send packet: type 91
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: receive packet: type 98
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: server_input_channel_req: channel 0 request subsystem reply 1
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: session_by_channel: session 0 channel 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: session_input_channel_req: session 0 req subsystem
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: subsystem request for sftp by user ssh-mitm
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: subsystem: cannot stat /usr/libexec/sftp-server: No such file or directory
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug1: subsystem: exec() /usr/libexec/sftp-server
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: Starting session: subsystem 'sftp' for ssh-mitm from 172.16.x.x port 52818 id 0
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 3 setting TCP_NODELAY
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug3: ssh_packet_set_tos: set IP_TOS 0x08
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 10 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 9 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12033]: debug2: fd 12 setting O_NONBLOCK
Sep 5 12:22:30 ubuntu1804lts sshd_mitm[12034]: debug3: MITM: SFTP server PID: 12034
Sep 5 12:22:30 ubuntu1804lts /home/ssh-mitm/bin/sftp-server[12034]: session opened for local user ssh-mitm from [172.16.x.x]
Sep 5 12:24:41 ubuntu1804lts /home/ssh-mitm/bin/sftp-server[12034]: fatal: Couldn't read packet: Connection reset by peer
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug3: send packet: type 99
Sep 5 12:24:41 ubuntu1804lts /home/ssh-mitm/bin/sftp-server[12034]: debug1: do_cleanup
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: Connection closed by 172.16.x.x port 52818
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug1: channel 0: free: server-session, nchannels 1
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug3: channel 0: status: The following connections are open:\r\n #0 server-session (t4 r0 i0/0 o0/0 fd 10/9 cc -1)\r\n
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: Close session: user ssh-mitm from 172.16.x.x port 52818 id 0
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug3: session_unused: session id 0 unused
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug1: do_cleanup
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: Transferred: sent 3064, received 1136 bytes
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: Closing connection to 172.16.x.x port 52818
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12033]: debug3: mm_request_send entering: type 50
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12030]: debug3: mm_request_receive entering
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12030]: debug3: monitor_read: checking request 50
Sep 5 12:24:41 ubuntu1804lts sshd_mitm[12030]: debug3: mm_answer_term: tearing down sessions
Also, the log above suggests that /usr/libexec/sftp-server isn't executed only because it doesn't exist. If it did exist on the host system, then AppArmor would presumably kill sshd_mitm...
Also, the log above suggests that /usr/libexec/sftp-server isn't executed only because it doesn't exist. If it did exist on the host system, then AppArmor would presumably kill sshd_mitm...
An investigation revealed that this isn't true. The logs claim that /usr/libexec/sftp-server is attempted to be executed, but the exec() calls are properly commented out.