Attachment 1482 Details for Bug 1458 – Trace of sftp hanging

Trace of sftp hanging

sftp-hang.log (text/plain), 6.21 KB, created by Nix on 2008-04-16 07:30:20 AEST

(hide)

Description:

Filename:

MIME Type:

Creator: Nix

Created: 2008-04-16 07:30:20 AEST

Size: 6.21 KB

patch

obsolete

>Script started on Tue 15 Apr 2008 15:03:00 BST
>$ sftp -vvvv user@site
>Connecting to [...]...
>OpenSSH_3.9p1, OpenSSL 0.9.7a Feb 19 2003
>debug1: Reading configuration data /etc/ssh/ssh_config
>debug1: Applying options for *
>debug2: ssh_connect: needpriv 0
>debug1: Connecting to [...] port 22.
>debug1: Connection established.
>debug1: identity file [...]/id_rsa type 1
>debug1: identity file [...]/id_dsa type -1
>debug1: Remote protocol version 2.0, remote software version 6.0.0.362 SSH Tectia Server
>debug1: no match: 6.0.0.362 SSH Tectia Server
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-2.0-OpenSSH_3.9p1
>debug2: fd 3 setting O_NONBLOCK
>debug1: SSH2_MSG_KEXINIT sent
>debug1: SSH2_MSG_KEXINIT received
>debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
>debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
>debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
>debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: first_kex_follows 0 
>debug2: kex_parse_kexinit: reserved 0 
>debug2: kex_parse_kexinit: diffie-hellman-group1-sha1
>debug2: kex_parse_kexinit: ssh-rsa
>debug2: kex_parse_kexinit: aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc,seed-cbc@ssh.com,crypticore128@ssh.com
>debug2: kex_parse_kexinit: aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc,seed-cbc@ssh.com,crypticore128@ssh.com
>debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,crypticore-mac@ssh.com
>debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,crypticore-mac@ssh.com
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: first_kex_follows 0 
>debug2: kex_parse_kexinit: reserved 0 
>debug2: mac_init: found hmac-md5
>debug1: kex: server->client aes128-cbc hmac-md5 none
>debug2: mac_init: found hmac-md5
>debug1: kex: client->server aes128-cbc hmac-md5 none
>debug2: dh_gen_key: priv key bits set: 151/256
>debug2: bits set: 513/1024
>debug1: sending SSH2_MSG_KEXDH_INIT
>debug1: expecting SSH2_MSG_KEXDH_REPLY
>debug3: check_host_in_hostfile: filename [...]
>debug3: check_host_in_hostfile: match line 2
>debug1: Host '[...]' is known and matches the RSA host key.
>debug1: Found key in [...]:2
>debug2: bits set: 529/1024
>debug1: ssh_rsa_verify: signature correct
>debug2: kex_derive_keys
>debug2: set_newkeys: mode 1
>debug1: SSH2_MSG_NEWKEYS sent
>debug1: expecting SSH2_MSG_NEWKEYS
>debug2: set_newkeys: mode 0
>debug1: SSH2_MSG_NEWKEYS received
>debug1: SSH2_MSG_SERVICE_REQUEST sent
>debug2: service_accept: ssh-userauth
>debug1: SSH2_MSG_SERVICE_ACCEPT received
>debug2: key: [...]/id_rsa (0x9410af8)
>debug2: key: [...]/id_dsa ((nil))
>debug1: Authentications that can continue: gssapi-with-mic,password,publickey,keyboard-interactive
>debug3: start over, passed a different list gssapi-with-mic,password,publickey,keyboard-interactive
>debug3: preferred gssapi-with-mic,publickey,keyboard-interactive,password
>debug3: authmethod_lookup gssapi-with-mic
>debug3: remaining preferred: publickey,keyboard-interactive,password
>debug3: authmethod_is_enabled gssapi-with-mic
>debug1: Next authentication method: gssapi-with-mic
>debug1: An invalid name was supplied
>Cannot determine realm for numeric host address
>
>debug1: An invalid name was supplied
>Cannot determine realm for numeric host address
>
>debug2: we did not send a packet, disable method
>debug3: authmethod_lookup publickey
>debug3: remaining preferred: keyboard-interactive,password
>debug3: authmethod_is_enabled publickey
>debug1: Next authentication method: publickey
>debug1: Offering public key: [...]/id_rsa
>debug3: send_pubkey_test
>debug2: we sent a publickey packet, wait for reply
>debug1: Authentications that can continue: gssapi-with-mic,password,publickey,keyboard-interactive
>debug1: Trying private key: [...]/id_dsa
>debug3: no such identity: [...]/id_dsa
>debug2: we did not send a packet, disable method
>debug3: authmethod_lookup keyboard-interactive
>debug3: remaining preferred: password
>debug3: authmethod_is_enabled keyboard-interactive
>debug1: Next authentication method: keyboard-interactive
>debug2: userauth_kbdint
>debug2: we sent a keyboard-interactive packet, wait for reply
>debug2: input_userauth_info_req
>Password Authentication:
>debug2: input_userauth_info_req: num_prompts 1
>GLRIMS's password: 
>debug3: packet_send2: adding 32 (len 22 padlen 10 extra_pad 64)
>debug1: Authentication succeeded (keyboard-interactive).
>debug2: fd 4 setting O_NONBLOCK
>debug3: fd 5 is O_NONBLOCK
>debug1: channel 0: new [client-session]
>debug3: ssh_session2_open: channel_new: 0
>debug2: channel 0: send open
>debug1: Entering interactive session.
>debug2: callback start
>debug2: client_session2_setup: id 0
>debug1: Sending subsystem: sftp
>debug2: channel 0: request subsystem confirm 1
>debug2: callback done
>debug2: channel 0: open confirm rwindow 65536 rmax 4096
>debug2: Remote version: 3
>debug2: Init extension: "newline@vandyke.com"
>debug3: Sent message fd 3 T:16 I:1
>debug3: SSH_FXP_REALPATH . -> /C:
>sftp> get [...]
>debug3: Looking up /C:/[...]
>debug3: Sent message fd 3 T:7 I:40
>debug3: Received stat reply T:105 I:40
>Fetching /C:/[...] to [...]
>debug3: Sent message fd 3 T:17 I:41
>debug3: Received stat reply T:105 I:41
>debug3: Sent message SSH2_FXP_OPEN I:42 P:/C:/[...]
>/C:/[...]             0%    0     0.0KB/s   --:-- ETAdebug3: Request range 0 -> 32767 (0/1)
>debug3: Received reply T:103 I:43 R:1
>debug3: Received data 0 -> 8763
>debug3: Short data block, re-requesting 8764 -> 32767 ( 1)
>debug3: Finish at 32768 ( 1)
>debug3: Received reply T:103 I:44 R:1
>debug3: Received data 8764 -> 8763
>debug3: Short data block, re-requesting 8764 -> 32767 ( 1)
>debug3: Finish at 32768 ( 1)
>debug3: Received reply T:103 I:45 R:1
>debug3: Received data 8764 -> 8763
>[repeat forever]

Actions: View

Attachments on bug 1458: 1482