Re: sftp/scp hangs at connection, but ssh is OK

On 2005-10-30 16:46:11 +0100, Martin Schr=F6der wrote:
> I've read the FAQ and googled, but I'm still stymied:
> ssh localhost works, but scp and sftp both hang.
> =

> ssh is OpenSSH_4.2p1, OpenSSL 0.9.6c [engine] 21 dec 2001
> =

> The last lines of an "scp -4 -vvv .bashrc localhost:/tmp/" are:
> ----------------------------------
> debug2: mac_init: found hmac-ripemd160
> debug1: kex: server->client aes128-cbc hmac-ripemd160 zlib@openssh.com
> debug2: mac_init: found hmac-ripemd160
> debug1: kex: client->server aes128-cbc hmac-ripemd160 zlib@openssh.com
> debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<2048<8192) sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
> debug2: dh_gen_key: priv key bits set: 152/320
> debug2: bits set: 1606/3191
> debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
> debug3: check_host_in_hostfile: filename /home/ms/.ssh/known_hosts
> debug3: key_read: type mismatch
> debug3: check_host_in_hostfile: match line 15
> debug1: Host 'localhost' is known and matches the RSA host key.
> debug1: Found key in /home/ms/.ssh/known_hosts:15
> debug2: bits set: 1587/3191
> 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: /home/ms/.ssh/id_dsa (0x809ad70)
> debug2: key: /home/ms/.ssh/id_rsa ((nil))
> 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: Offering public key: /home/ms/.ssh/id_dsa
> debug3: send_pubkey_test
> debug2: we sent a publickey packet, wait for reply
> debug1: Server accepts key: pkalg ssh-dss blen 432
> debug2: input_userauth_pk_ok: fp 20:e2:42:bb:b2:48:6a:07:db:5c:99:5f:28:1=
c:17:88
> debug3: sign_and_send_pubkey
> debug1: Enabling compression at level 6.
> debug1: Authentication succeeded (publickey).
> debug2: fd 6 setting O_NONBLOCK
> debug2: fd 9 setting 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 command: scp -v -t /tmp/
> debug2: channel 0: request exec confirm 0
> debug2: callback done
> debug2: channel 0: open confirm rwindow 0 rmax 32768
> debug2: channel 0: rcvd adjust 131072
> ----------------------------------
> The sshd (running with DEBUG3) produces this:
> ----------------------------------
> Oct 30 16:23:13 dream sshd[2122]: Found matching DSA key: 20:e2:42:bb:b2:=
48:6a:07:db:5c:99:5f:28:1c:17:88
> Oct 30 16:23:13 dream sshd[2122]: debug1: restore_uid: 0/0
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_answer_keyallowed: key 0x80a=
3d70 is allowed
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_send entering: type =
21
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_receive entering
> Oct 30 16:23:13 dream sshd[2122]: debug3: monitor_read: checking request =
22
> Oct 30 16:23:13 dream sshd[2122]: debug1: ssh_dss_verify: signature corre=
ct
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_answer_keyverify: key 0x809a=
c58 signature verified
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_send entering: type =
23
> Oct 30 16:23:13 dream sshd[2122]: Accepted publickey for ms from 127.0.0.=
1 port 32838 ssh2
> Oct 30 16:23:13 dream sshd[2122]: debug1: monitor_child_preauth: ms has b=
een authenticated by privileged process
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_get_keystate: Waiting for ne=
w keys
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_receive_expect enter=
ing: type 24
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_receive entering
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_newkeys_from_blob: 0x809aaa0=
(140)
> Oct 30 16:23:13 dream sshd[2122]: debug2: mac_init: found hmac-ripemd160
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_get_keystate: Waiting for se=
cond key
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_newkeys_from_blob: 0x809aaa0=
(140)
> Oct 30 16:23:13 dream sshd[2122]: debug2: mac_init: found hmac-ripemd160
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_get_keystate: Getting compre=
ssion state
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_get_keystate: Getting Networ=
k I/O buffers
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_share_sync: Share sync
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_share_sync: Share sync end
> Oct 30 16:23:13 dream sshd[2124]: debug1: permanently_set_uid: 500/100
> Oct 30 16:23:13 dream sshd[2124]: debug2: set_newkeys: mode 0
> Oct 30 16:23:13 dream sshd[2124]: debug2: set_newkeys: mode 1
> Oct 30 16:23:13 dream sshd[2124]: debug1: Entering interactive session fo=
r SSH2.
> Oct 30 16:23:13 dream sshd[2124]: debug2: fd 5 setting O_NONBLOCK
> Oct 30 16:23:13 dream sshd[2124]: debug2: fd 6 setting O_NONBLOCK
> Oct 30 16:23:13 dream sshd[2124]: debug1: server_init_dispatch_20
> Oct 30 16:23:13 dream sshd[2124]: debug1: server_input_channel_open: ctyp=
e session rchan 0 win 131072 max 32768
> Oct 30 16:23:13 dream sshd[2124]: debug1: input_session_request
> Oct 30 16:23:13 dream sshd[2124]: debug1: channel 0: new [server-session]
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_new: init
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_new: session 0
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_open: channel 0
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_open: session 0: link w=
ith channel 0
> Oct 30 16:23:13 dream sshd[2124]: debug1: server_input_channel_open: conf=
irm session
> Oct 30 16:23:13 dream sshd[2124]: debug1: server_input_channel_req: chann=
el 0 request exec reply 0
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_by_channel: session 0 c=
hannel 0
> Oct 30 16:23:13 dream sshd[2124]: debug1: session_input_channel_req: sess=
ion 0 req exec
> Oct 30 16:23:13 dream sshd[2125]: debug3: channel 0: close_fds r -1 w -1 =
e -1 c -1
> Oct 30 16:23:13 dream sshd[2124]: debug2: fd 8 setting O_NONBLOCK
> Oct 30 16:23:13 dream sshd[2124]: debug3: fd 8 is O_NONBLOCK
> Oct 30 16:23:13 dream sshd[2124]: debug2: fd 10 setting O_NONBLOCK
> Oct 30 16:23:13 dream sshd[2122]: debug2: User child is on pid 2124
> Oct 30 16:23:13 dream sshd[2122]: debug3: mm_request_receive entering
> ----------------------------------
> After an Ctrl-C scp exits with
> ----------------------------------
> debug1: channel 0: free: client-session, nchannels 1
> debug3: channel 0: status: The following connections are open:
> #0 client-session (t4 r0 i0/0 o0/0 fd 6/9 cfd -1)
> =

> debug3: channel 0: close_fds r 6 w 9 e 10 c -1
> debug1: fd 0 clearing O_NONBLOCK
> debug1: fd 1 clearing O_NONBLOCK
> Killed by signal 2.
> ----------------------------------
> And the sshd logs
> ----------------------------------
> Oct 30 16:26:09 dream sshd[2124]: Connection closed by 127.0.0.1
> Oct 30 16:26:09 dream sshd[2124]: debug1: channel 0: free: server-session=
, nchannels 1
> Oct 30 16:26:09 dream sshd[2124]: debug3: channel 0: status: The followin=
g connections are open:\r\n #0 server-session (t4 r0 i0/0 o0/0 fd 8/8 cfd =
-1)\r\n
> Oct 30 16:26:09 dream sshd[2124]: debug3: channel 0: close_fds r 8 w 8 e =
10 c -1
> Oct 30 16:26:09 dream sshd[2124]: debug1: session_close: session 0 pid 21=
25
> Oct 30 16:26:09 dream sshd[2124]: debug1: do_cleanup
> Oct 30 16:26:09 dream sshd[2124]: Closing connection to 127.0.0.1
> Oct 30 16:26:09 dream sshd[2124]: debug3: mm_request_send entering: type =
58
> Oct 30 16:26:09 dream sshd[2122]: debug3: monitor_read: checking request =
58
> Oct 30 16:26:09 dream sshd[2122]: debug3: mm_answer_term: tearing down se=
ssions
> ----------------------------------
> =

> The system is a Suse 8.0 (Linux 2.4.18).
> =

> Any idea how to fix this?

I tried this on secureshell, but got only garbage or pointers to
the FAQ. The FAQ doesn't help:
-------------
> echo +`ssh localhost /bin/true`+
++
-------------

Thanks in advance
Martin
-- =

http://www.tm.oneiros.de

_______________________________________________
openssh-unix-dev mailing list
openssh-unix-dev@mindrot.org
http://www.mindrot.org/mailman/listi...enssh-unix-dev