Subject: libssh2 is hanging during a file transfert

libssh2 is hanging during a file transfert

From: Micka <mickamusset_at_gmail.com>
Date: Tue, 7 Jul 2020 12:13:46 +0200

Hi,

I'm trying to send data to a server with openssh 7.9p1, but it's hanging
somewhere.

the client stop at the line :
  Jul 7 11:52:16 TOTO sshd[19553]: debug3: channel 0: will not send data
after close

and after 5 minutes the client closes the connection, why ?

This is the trace of the server openssh : ( DEBUG3 level)

Jul 7 11:52:15 TOTO sshd[31175]: debug3: fd 6 is not O_NONBLOCK
Jul 7 11:52:15 TOTO sshd[31175]: debug1: Forked child 19126.
Jul 7 11:52:15 TOTO sshd[31175]: debug3: send_rexec_state: entering fd = 9
config len 970
Jul 7 11:52:15 TOTO sshd[31175]: debug3: ssh_msg_send: type 0
Jul 7 11:52:15 TOTO sshd[31175]: debug3: send_rexec_state: done
Jul 7 11:52:15 TOTO sshd[19126]: debug3: oom_adjust_restore
Jul 7 11:52:15 TOTO sshd[19126]: debug1: Set /proc/self/oom_score_adj to 0
Jul 7 11:52:15 TOTO sshd[19126]: debug1: rexec start in 6 out 6 newsock 6
pipe 8 sock 9
Jul 7 11:52:15 TOTO sshd[19126]: debug1: inetd sockets after dupping: 5, 5
Jul 7 11:52:15 TOTO sshd[19126]: Connection from 10.91.140.30 port 49822
on 10.91.141.1 port 22
Jul 7 11:52:15 TOTO sshd[19126]: debug1: Client protocol version 2.0;
client software version libssh2_1.9.0_DEV
Jul 7 11:52:15 TOTO sshd[19126]: debug1: no match: libssh2_1.9.0_DEV
Jul 7 11:52:15 TOTO sshd[19126]: debug1: Local version string
SSH-2.0-OpenSSH_7.9
Jul 7 11:52:15 TOTO sshd[19126]: debug2: fd 5 setting O_NONBLOCK
Jul 7 11:52:15 TOTO sshd[19126]: debug3: ssh_sandbox_init: preparing
seccomp filter sandbox
Jul 7 11:52:15 TOTO sshd[19126]: debug2: Network child is on pid 19151
Jul 7 11:52:15 TOTO sshd[19126]: debug3: preauth child monitor started
Jul 7 11:52:15 TOTO sshd[19126]: debug3: privsep user:group 106:65534
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: permanently_set_uid: 106/65534
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: ssh_sandbox_child: setting
PR_SET_NO_NEW_PRIVS [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: ssh_sandbox_child: attaching
seccomp filter program [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: list_hostkey_types:
rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 20 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 20 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_KEXINIT received
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: local server KEXINIT proposal
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: KEX algorithms:
diffie-hellman-group-exchange-sha256 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: host key algorithms:
rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: ciphers ctos:
aes256-ctr,aes192-ctr,aes128-ctr [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: ciphers stoc:
aes256-ctr,aes192-ctr,aes128-ctr [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: MACs ctos:
hmac-sha2-512,hmac-sha2-256 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: MACs stoc:
hmac-sha2-512,hmac-sha2-256 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: compression ctos: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: compression stoc: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: languages ctos: [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: languages stoc: [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: first_kex_follows 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: reserved 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: peer client KEXINIT proposal
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: KEX algorithms:
ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,curve25519-sha256,
curve25519-sha256_at_libssh.org,diffie-hellman-group14-sha256,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: host key algorithms: ssh-rsa
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: ciphers ctos:
aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc_at_lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: ciphers stoc:
aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc_at_lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: MACs ctos:
hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,
hmac-ripemd160_at_openssh.com [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: MACs stoc:
hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,
hmac-ripemd160_at_openssh.com [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: compression ctos: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: compression stoc: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: languages ctos: [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: languages stoc: [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: first_kex_follows 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: reserved 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: kex: algorithm:
diffie-hellman-group-exchange-sha256 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: kex: host key algorithm: ssh-rsa
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: kex: client->server cipher:
aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: kex: server->client cipher:
aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: expecting
SSH2_MSG_KEX_DH_GEX_REQUEST [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 34 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST
received [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 0
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_choose_dh: waiting for
MONITOR_ANS_MODULI [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 1 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 0
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_moduli: got parameters:
2048 4096 8192
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 1
Jul 7 11:52:15 TOTO sshd[19126]: debug2: monitor_read: 0 used once,
disabling now
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_choose_dh: remaining 0
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 31 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: bits set: 1978/4096 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: expecting
SSH2_MSG_KEX_DH_GEX_INIT [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 32 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: bits set: 2017/4096 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_sshkey_sign entering [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 6
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 6
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_sign
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_sign: hostkey proof
signature 0x80311540(271)
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 7
Jul 7 11:52:15 TOTO sshd[19126]: debug2: monitor_read: 6 used once,
disabling now
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_sshkey_sign: waiting for
MONITOR_ANS_SIGN [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 7 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 33 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 21 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: set_newkeys: mode 1 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: rekey after 4294967296 blocks
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: expecting SSH2_MSG_NEWKEYS
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 21 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: SSH2_MSG_NEWKEYS received
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: set_newkeys: mode 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: rekey after 4294967296 blocks
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: KEX done [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 5 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 6 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 50 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: userauth-request for user toto
service ssh-connection method none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: attempt 0 failures 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_getpwnamallow entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 8
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_getpwnamallow: waiting for
MONITOR_ANS_PWNAM [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 9 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 8
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_pwnamallow
Jul 7 11:52:15 TOTO sshd[19126]: debug2: parse_server_config: config
reprocess config len 970
Jul 7 11:52:15 TOTO sshd[19126]: debug3: auth_shadow_acctexpired: today
18450 sp_expire -1 days left -18451
Jul 7 11:52:15 TOTO sshd[19126]: debug3: account expiration disabled
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_pwnamallow: sending
MONITOR_ANS_PWNAM: 1
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 9
Jul 7 11:52:15 TOTO sshd[19126]: debug2: monitor_read: 8 used once,
disabling now
Jul 7 11:52:15 TOTO sshd[19126]: debug2: input_userauth_request: setting
up authctxt for toto [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_inform_authserv entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 4
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_auth2_read_banner entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 10
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 11 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 4
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_authserv:
service=ssh-connection, style=
Jul 7 11:52:15 TOTO sshd[19126]: debug2: monitor_read: 4 used once,
disabling now
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 10
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 11
Jul 7 11:52:15 TOTO sshd[19126]: debug2: monitor_read: 10 used once,
disabling now
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 53 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: userauth_send_banner: sent
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: input_userauth_request: try
method none [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: user_specific_delay: user
specific delay 0.000ms [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: ensure_minimum_time_since:
elapsed 73.257ms, delaying 64.508ms (requested 8.610ms) [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: userauth_finish: failure
partial=0 next methods="publickey" [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: send packet: type 51 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: receive packet: type 50 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: userauth-request for user toto
service ssh-connection method publickey [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: attempt 1 failures 0 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug2: input_userauth_request: try
method publickey [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug1: userauth_pubkey: test pkalg
ssh-rsa pkblob RSA SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_key_allowed entering [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 22
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_key_allowed: waiting for
MONITOR_ANS_KEYALLOWED [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 23 [preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: monitor_read: checking request 22
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_keyallowed entering
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_keyallowed:
key_from_blob: 0x80306160
Jul 7 11:52:15 TOTO sshd[19126]: debug1: temporarily_use_uid: 1001/1001
(e=0/0)
Jul 7 11:52:15 TOTO sshd[19126]: debug1: trying public key file
/home/test.pub
Jul 7 11:52:15 TOTO sshd[19126]: debug1: fd 4 clearing O_NONBLOCK
Jul 7 11:52:15 TOTO sshd[19126]: debug1: /home/test.pub:1: matching key
found: RSA SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4
Jul 7 11:52:15 TOTO sshd[19126]: debug1: /home/test.pub:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
Jul 7 11:52:15 TOTO sshd[19126]: Accepted key RSA
SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4 found at /home/test.pub:1
Jul 7 11:52:15 TOTO sshd[19126]: debug1: restore_uid: 0/0
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_answer_keyallowed: publickey
authentication test: RSA key is allowed
Jul 7 11:52:15 TOTO sshd[19126]: debug3: mm_request_send entering: type 23
Jul 7 11:52:16 TOTO sshd[19126]: debug3: send packet: type 60 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug2: userauth_pubkey: authenticated 0
pkalg ssh-rsa [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: user_specific_delay: user
specific delay 0.000ms [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: ensure_minimum_time_since:
elapsed 10.037ms, delaying 7.184ms (requested 8.610ms) [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: Postponed publickey for toto from
10.91.140.30 port 49822 ssh2 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: receive packet: type 50 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug1: userauth-request for user toto
service ssh-connection method publickey [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug1: attempt 2 failures 0 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug2: input_userauth_request: try
method publickey [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: userauth_pubkey: have ssh-rsa
signature for RSA SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_key_allowed entering [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_send entering: type 22
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_key_allowed: waiting for
MONITOR_ANS_KEYALLOWED [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 23 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:16 TOTO sshd[19126]: debug3: monitor_read: checking request 22
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_answer_keyallowed entering
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_answer_keyallowed:
key_from_blob: 0x80309fd0
Jul 7 11:52:16 TOTO sshd[19126]: debug1: temporarily_use_uid: 1001/1001
(e=0/0)
Jul 7 11:52:16 TOTO sshd[19126]: debug1: trying public key file
/home/test.pub
Jul 7 11:52:16 TOTO sshd[19126]: debug1: fd 4 clearing O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19126]: debug1: /home/test.pub:1: matching key
found: RSA SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4
Jul 7 11:52:16 TOTO sshd[19126]: debug1: /home/test.pub:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
Jul 7 11:52:16 TOTO sshd[19126]: Accepted key RSA
SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4 found at /home/test.pub:1
Jul 7 11:52:16 TOTO sshd[19126]: debug1: restore_uid: 0/0
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_answer_keyallowed: publickey
authentication: RSA key is allowed
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_send entering: type 23
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_sshkey_verify entering
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_send entering: type 24
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_sshkey_verify: waiting for
MONITOR_ANS_KEYVERIFY [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 25 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive entering
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:16 TOTO sshd[19126]: debug3: monitor_read: checking request 24
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_answer_keyverify: publickey
0x80309fd0 signature verified
Jul 7 11:52:16 TOTO sshd[19126]: debug1: auth_activate_options: setting
new authentication options
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_send entering: type 25
Jul 7 11:52:16 TOTO sshd[19126]: Accepted publickey for toto from
10.91.140.30 port 49822 ssh2: RSA
SHA256:fVQ7eL1KeCgpq4/BSsnou/pVnQv8mCouzqfNolAgbp4
Jul 7 11:52:16 TOTO sshd[19126]: debug1: monitor_child_preauth: toto has
been authenticated by privileged process
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_get_keystate: Waiting for new
keys
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive_expect
entering: type 26
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_get_keystate: GOT new keys
Jul 7 11:52:16 TOTO sshd[19126]: debug1: auth_activate_options: setting
new authentication options [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug2: userauth_pubkey: authenticated 1
pkalg ssh-rsa [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: user_specific_delay: user
specific delay 0.000ms [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: ensure_minimum_time_since:
elapsed 12.239ms, delaying 4.982ms (requested 8.610ms) [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: send packet: type 52 [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_request_send entering: type 26
[preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug3: mm_send_keystate: Finished
sending state [preauth]
Jul 7 11:52:16 TOTO sshd[19126]: debug1: monitor_read_log: child log fd
closed
Jul 7 11:52:16 TOTO sshd[19126]: debug3: ssh_sandbox_parent_finish:
finished
Jul 7 11:52:16 TOTO sshd[19126]: User child is on pid 19553
Jul 7 11:52:16 TOTO sshd[19553]: debug1: permanently_set_uid: 1001/1001
Jul 7 11:52:16 TOTO sshd[19553]: debug3: monitor_apply_keystate:
packet_set_state
Jul 7 11:52:16 TOTO sshd[19553]: debug2: set_newkeys: mode 0
Jul 7 11:52:16 TOTO sshd[19553]: debug1: rekey after 4294967296 blocks
Jul 7 11:52:16 TOTO sshd[19553]: debug2: set_newkeys: mode 1
Jul 7 11:52:16 TOTO sshd[19553]: debug1: rekey after 4294967296 blocks
Jul 7 11:52:16 TOTO sshd[19553]: debug1: ssh_packet_set_postauth: called
Jul 7 11:52:16 TOTO sshd[19553]: debug3: ssh_packet_set_state: done
Jul 7 11:52:16 TOTO sshd[19553]: debug3: notify_hostkeys: key 0: ssh-rsa
SHA256:vYlhpVfmXfMCmgD8vuI3qK7ppf3aRj8qhg3hj8OtJCI
Jul 7 11:52:16 TOTO sshd[19553]: debug3: notify_hostkeys: sent 1 hostkeys
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 80
Jul 7 11:52:16 TOTO sshd[19553]: debug1: active: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
Jul 7 11:52:16 TOTO sshd[19553]: debug3: sending debug message:
/home/test.pub:1: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 4
Jul 7 11:52:16 TOTO sshd[19553]: debug3: sending debug message:
/home/test.pub:1: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 4
Jul 7 11:52:16 TOTO sshd[19553]: debug1: Entering interactive session for
SSH2.
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 7 setting O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 9 setting O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19553]: debug1: server_init_dispatch
Jul 7 11:52:16 TOTO sshd[19553]: debug3: receive packet: type 90
Jul 7 11:52:16 TOTO sshd[19553]: debug1: server_input_channel_open: ctype
session rchan 0 win 2097152 max 32768
Jul 7 11:52:16 TOTO sshd[19553]: debug1: input_session_request
Jul 7 11:52:16 TOTO sshd[19553]: debug1: channel 0: new [server-session]
Jul 7 11:52:16 TOTO sshd[19553]: debug2: session_new: allocate (allocated
0 max 10)
Jul 7 11:52:16 TOTO sshd[19553]: debug3: session_unused: session id 0
unused
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_new: session 0
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_open: channel 0
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_open: session 0: link
with channel 0
Jul 7 11:52:16 TOTO sshd[19553]: debug1: server_input_channel_open:
confirm session
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 91
Jul 7 11:52:16 TOTO sshd[19553]: debug3: receive packet: type 98
Jul 7 11:52:16 TOTO sshd[19553]: debug1: server_input_channel_req: channel
0 request subsystem reply 1
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_by_channel: session 0
channel 0
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_input_channel_req:
session 0 req subsystem
Jul 7 11:52:16 TOTO sshd[19553]: debug2: subsystem request for sftp by
user toto
Jul 7 11:52:16 TOTO sshd[19553]: debug1: subsystem: exec()
/usr/lib/openssh/sftp-server -l DEBUG3
Jul 7 11:52:16 TOTO sshd[19553]: Starting session: subsystem 'sftp' for
toto from 10.91.140.30 port 49822 id 0
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 5 setting TCP_NODELAY
Jul 7 11:52:16 TOTO sshd[19553]: debug3: ssh_packet_set_tos: set IP_TOS
0x20
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 12 setting O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 11 setting O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19553]: debug2: fd 14 setting O_NONBLOCK
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 99
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: read 43 from efd 14
Jul 7 11:52:16 TOTO sshd[19553]: debug3: channel 0: discard efd
Jul 7 11:52:16 TOTO sshd[19553]: debug1: Received SIGCHLD.
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_by_pid: pid 19576
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_exit_message: session 0
channel 0 pid 19576
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: request exit-status
confirm 0
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 98
Jul 7 11:52:16 TOTO sshd[19553]: debug1: session_exit_message: release
channel 0
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: write failed
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: chan_shutdown_write
(i0 o0 sock -1 wfd 11 efd 14 [ignore])
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: send eow
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: output open -> closed
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: read<=0 rfd 12 len 0
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: read failed
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: chan_shutdown_read (i0
o3 sock -1 wfd 12 efd 14 [ignore])
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: input open -> drain
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: read 0 from efd 14
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: closing read-efd 14
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: ibuf empty
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: send eof
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 96
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: input drain -> closed
Jul 7 11:52:16 TOTO sshd[19553]: debug2: channel 0: send close
Jul 7 11:52:16 TOTO sshd[19553]: debug3: send packet: type 97
Jul 7 11:52:16 TOTO sshd[19553]: debug2: notify_done: reading
Jul 7 11:52:16 TOTO sshd[19553]: debug3: channel 0: will not send data
after close
Jul 7 11:57:15 TOTO sshd[19553]: debug3: receive packet: type 1
Jul 7 11:57:15 TOTO sshd[19553]: Received disconnect from 10.91.140.30
port 49822:11: Shutdown
Jul 7 11:57:15 TOTO sshd[19553]: Disconnected from user toto 10.91.140.30
port 49822
Jul 7 11:57:15 TOTO sshd[19553]: debug1: do_cleanup
Jul 7 11:57:15 TOTO sshd[19126]: debug3: mm_request_receive entering
Jul 7 11:57:15 TOTO sshd[19126]: debug1: do_cleanup

_______________________________________________
libssh2-devel https://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
Received on 2020-07-07