Hello,
When running scp (from openssh-3.4p1) on our linux systems we are
experiencing hangs after authentication. According to the debug
messages, authentication succeeds but the file itself is not
transferred. Openssh is built using OpenSSL 0.9.6d.
The command
scp foo 192.168.1.111:/tmp
will hang until the connection times out.
Below are the client and server side logs. An strace of the client and
server sides (using -f to follow the child process) shows that both are
stuck in select() with NULL timeout. So they will both wait forever
until they receive some input.
Using ssh to log in interactively works fine.
The problem is shown below using password authentication, but it also
happens using RSA authentication.
We have a system with identical hardware and the same ssh installation
(Openssh-3.4p1 + OpenSSL 0.9.6d) that does shows the problem only
sporadically. On the system that generated the logs below, scp always
fails.
The one peculiarity of our system is that /var is on a separate
partition which is reformatted on boot. A skeleton /var filesystem is
copied into the new /var. This is because these systems are designed for
unattended kiosks, where the only service intervention is to cycle the
power. I have no idea if this is relevant or not, but it is a
peculiarity.
Our linux kernel is 2.4.17 and the glibc is 2.2.5. The system is built
from a Linux from Scratch "distribution".
I would appreciate knowing if anyone has seen something like this before
and how it might be worked around.
Thanks!
Best Wishes,
Greg Wright
The portion of the client strace log that shows the trouble is below. (I
can provide the rest if it helps.)
[pid 1438] close(4) = 0
[pid 1438] dup(0) = 4
[pid 1438] dup(1) = 5
[pid 1438] dup(2) = 6
[pid 1438] ioctl(4, TCGETS, 0xbffff604) = -1 EINVAL (Invalid argument)
[pid 1438] fcntl(4, F_GETFL) = 0 (flags O_RDONLY)
[pid 1438] fcntl(4, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
[pid 1438] ioctl(5, TCGETS, 0xbffff604) = -1 EINVAL (Invalid argument)
[pid 1438] fcntl(5, F_GETFL) = 0x1 (flags O_WRONLY)
[pid 1438] fcntl(5, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
[pid 1438] ioctl(6, TCGETS, {B38400 opost isig icanon echo ...}) = 0
[pid 1438] gettimeofday({1027615805, 895450}, NULL) = 0
[pid 1438] rt_sigaction(SIGINT, {0x80538a4, [], SA_RESTART|0x4000000},
{SIG_DFL}, 8) = 0
[pid 1438] rt_sigaction(SIGQUIT, {0x80538a4, [], SA_RESTART|0x4000000},
{SIG_DFL}, 8) = 0
[pid 1438] rt_sigaction(SIGTERM, {0x80538a4, [], SA_RESTART|0x4000000},
{SIG_DFL}, 8) = 0
[pid 1438] select(7, [3], [3], NULL, NULL) = 1 (out [3])
[pid 1438] write(3,
"\234\231\277\177\16\315\317\207m\306\3522F\203<\275w\326"..., 64)
= 64
[pid 1438] select(7, [3], [], NULL, NULL) = 1 (in [3])
[pid 1438] read(3,
"\353\246&.\207\10\276\333K\203\325\267N\207\247\266\212"...,
8192) = 48
[pid 1438] getsockname(3, {sin_family=AF_INET, sin_port=htons(2019),
sin_addr=inet_addr("192.168.1.5")}}, [16]) = 0
[pid 1438] setsockopt(3, SOL_IP, IP_TOS, [8], 4) = 0
[pid 1438] select(7, [3], [3], NULL, NULL) = 1 (out [3])
[pid 1438] write(3,
"\v{fu\371\332O\370\376O\6)\226\362\303\32I\216\32Z\t\303"..., 64) =
64
[pid 1438] select(7, [3], [], NULL, NULL
...and there it stops.
The client side log:
h> scp -v foo 192.168.1.111:/tmp
Executing: program /usr/bin/ssh host 192.168.1.111, user (unspecified),
command scp -v -t /tmp
OpenSSH_3.4p1, SSH protocols 1.5/2.0, OpenSSL 0x0090604f
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Rhosts Authentication disabled, originating port will not be
trusted.
debug1: ssh_connect: needpriv 0
debug1: Connecting to 192.168.1.111 [192.168.1.111] port 22.
debug1: Connection established.
debug1: identity file /root/.ssh/identity type 0
debug1: identity file /root/.ssh/id_rsa type 1
debug1: identity file /root/.ssh/id_dsa type 2
debug1: Remote protocol version 1.99, remote software version
OpenSSH_3.4p1
debug1: match: OpenSSH_3.4p1 pat OpenSSH*
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_3.4p1
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: dh_gen_key: priv key bits set: 116/256
debug1: bits set: 1561/3191
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host '192.168.1.111' is known and matches the RSA host key.
debug1: Found key in /root/.ssh/known_hosts:41
debug1: bits set: 1556/3191
debug1: ssh_rsa_verify: signature correct
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: done: ssh_kex2.
debug1: send SSH2_MSG_SERVICE_REQUEST
debug1: service_accept: ssh-userauth
debug1: got SSH2_MSG_SERVICE_ACCEPT
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: next auth method to try is publickey
debug1: userauth_pubkey_agent: testing agent key /root/.ssh/id_rsa
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: userauth_pubkey_agent: testing agent key /root/.ssh/id_dsa
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: try pubkey: /root/.ssh/id_rsa
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: try pubkey: /root/.ssh/id_dsa
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: next auth method to try is keyboard-interactive
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: next auth method to try is password
root at 192.168.1.111's password:
debug1: ssh-userauth2 successful: method password
debug1: fd 4 setting O_NONBLOCK
debug1: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug1: send channel open 0
debug1: Entering interactive session.
debug1: ssh_session2_setup: id 0
debug1: Sending command: scp -v -t /tmp
debug1: channel request 0: exec
debug1: channel 0: open confirm rwindow 0 rmax 32768
The server side log:
debug1: sshd version OpenSSH_3.4p1
debug1: private host key: #0 type 0 RSA1
debug1: read PEM private key done: type RSA
debug1: private host key: #1 type 1 RSA
debug1: read PEM private key done: type DSA
debug1: private host key: #2 type 2 DSA
socket: Address family not supported by protocol
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
Generating 768 bit RSA key.
RSA key generation complete.
debug1: Server will not fork when running in debugging mode.
Connection from 192.168.1.5 port 1743
debug1: Client protocol version 2.0; client software version
OpenSSH_3.4p1
debug1: match: OpenSSH_3.4p1 pat OpenSSH*
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-1.99-OpenSSH_3.4p1
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug1: dh_gen_key: priv key bits set: 121/256
debug1: bits set: 1598/3191
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug1: bits set: 1618/3191
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user root service ssh-connection method
none
debug1: attempt 0 failures 0
Failed none for root from 192.168.1.5 port 1743 ssh2
Failed none for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
publickey
debug1: attempt 1 failures 1
debug1: test whether pkalg/pkblob are acceptable
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys
debug1: restore_uid
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys2
debug1: restore_uid
Failed publickey for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
publickey
debug1: attempt 2 failures 2
debug1: test whether pkalg/pkblob are acceptable
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys
debug1: restore_uid
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys2
debug1: restore_uid
Failed publickey for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
publickey
debug1: attempt 3 failures 3
debug1: test whether pkalg/pkblob are acceptable
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys
debug1: restore_uid
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys2
debug1: restore_uid
Failed publickey for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
publickey
debug1: attempt 4 failures 4
debug1: test whether pkalg/pkblob are acceptable
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys
debug1: restore_uid
debug1: temporarily_use_uid: 0/0 (e=0)
debug1: trying public key file /root/.ssh/authorized_keys2
debug1: restore_uid
Failed publickey for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
keyboard-interactive
debug1: attempt 5 failures 5
debug1: keyboard-interactive devs
debug1: auth2_challenge: user=root devs=
debug1: kbdint_alloc: devices ''
Failed keyboard-interactive for root from 192.168.1.5 port 1743 ssh2
debug1: userauth-request for user root service ssh-connection method
password
debug1: attempt 6 failures 6
Accepted password for root from 192.168.1.5 port 1743 ssh2
debug1: monitor_child_preauth: root has been authenticated by privileged
processAccepted password for root from 192.168.1.5 port 1743 ssh2
debug1: newkeys: mode 0
debug1: newkeys: mode 1
debug1: Entering interactive session for SSH2.
debug1: fd 3 setting O_NONBLOCK
debug1: fd 7 setting O_NONBLOCK
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 131072 max
32768
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: init
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
Read error from remote host: Connection timed out
debug1: Calling cleanup 0x8060534(0x0)
debug1: channel_free: channel 0: server-session, nchannels 1
debug1: Calling cleanup 0x806c570(0x0)
--
Gregory Wright
Chief Technical Officer
PacketStorm Communications, Inc.
20 Meridian Road
Eatontown, New Jersey 07724
1 732 544-2434 ext. 206
1 732 544-2437 [fax]
gwright at packetstorm.com
--
Gregory Wright
Chief Technical Officer
PacketStorm Communications, Inc.
20 Meridian Road
Eatontown, New Jersey 07724
1 732 544-2434 ext. 206
1 732 544-2437 [fax]
gwright at packetstorm.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://lists.mindrot.org/pipermail/openssh-unix-dev/attachments/20020725/38526f0f/attachment.html
