openssh-SNAP-20001016

[Pekka Savola]

On Tue, 24 Oct 2000, Markus Friedl wrote:

> On Tue, Oct 24, 2000 at 01:37:42PM -0400, Rob Hagopian wrote:
> > Using openssh-SNAP-20001016 all of our problems with hanging connections
> > have gone away (woohoo!), and it seems to be working flawlessly, but I am
> > seeing messages like this in syslog:
> > 
> > Oct 24 16:57:48 dhumb301 sshd[17752]: error: channel 0: internal error: we
> > do not read, but chan_read_failed for istate 8
> > Oct 24 16:57:59 dhumb301 sshd[17771]: error: select: Bad file descriptor
> > Oct 24 16:58:30 dhumb301 sshd[17876]: error: channel 0: internal error: we
> > do not read, but chan_read_failed for istate 8
> > 
> > This is FreeBSD 3.4... Any ideas?
> 
> i need a full trace for this. please start 'sshd -d -p 1234' and
> connect with 'ssh -v -p 1234 host'.

This (internal errors; I haven't seen Bad file descriptor errors) only
seems to happen with scp2.  Traces:

--- sshd [there's also syslogd logging some events to the same trace] ---
root: /home/pekkas$ sshd -d -p 2022
debug1: sshd version OpenSSH_2.3.0p1
debug1: Seeding random number generator
debug1: read DSA private key done
debug1: Seeding random number generator
debug1: Bind to port 2022 on 0.0.0.0.
Server listening on 0.0.0.0 port 2022.
Generating 768 bit RSA key.
debug1: Seeding random number generator
debug1: Seeding random number generator
RSA key generation complete.
debug1: Server will not fork when running in debugging mode.
Connection from x.y.z.w port 1336
debug1: Client protocol version 2.0; client software version OpenSSH-2.1
debug1: match: OpenSSH-2.1 pat ^OpenSSH-2\.[01]

Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-1.99-OpenSSH_2.3.0p1
debug1: send KEXINIT
debug1: done
debug1: wait KEXINIT
debug1: got kexinit: diffie-hellman-group1-sha1
debug1: got kexinit: ssh-dss
debug1: got kexinit: blowfish-cbc
debug1: got kexinit: blowfish-cbc
debug1: got kexinit: hmac-sha1,hmac-md5,hmac-ripemd160 at openssh.com
debug1: got kexinit: hmac-sha1,hmac-md5,hmac-ripemd160 at openssh.com
debug1: got kexinit: none
debug1: got kexinit: none
debug1: got kexinit: 
debug1: got kexinit: 
debug1: first kex follow: 0 
debug1: reserved: 0 
debug1: done
debug1: kex: client->server blowfish-cbc hmac-sha1 none
debug1: kex: server->client blowfish-cbc hmac-sha1 none
debug1: Wait SSH2_MSG_KEXDH_INIT.
debug1: bits set: 516/1024
debug1: bits set: 511/1024
debug1: sig size 20 20
debug1: send SSH2_MSG_NEWKEYS.
debug1: done: send SSH2_MSG_NEWKEYS.
debug1: Wait SSH2_MSG_NEWKEYS.
debug1: GOT SSH2_MSG_NEWKEYS.
debug1: done: KEX2.
debug1: userauth-request for user pekkas service ssh-connection method
none
debug1: attempt #1
debug1: Starting up PAM with username "pekkas"
Failed none for pekkas from x.y.z.w port 1336 ssh2
debug1: userauth-request for user pekkas service ssh-connection method
password
debug1: attempt #2
debug1: PAM Password authentication accepted for user "pekkas"
debug1: PAM setting rhost to "xx.yy.zz.ww"
Accepted password for pekkas from x.y.z.w port 1336 ssh2
debug1: Entering interactive session for SSH2.
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 65536 max
32768
debug1: open session
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: confirm session
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 channel 0 request exec reply
0
debug1: PAM establishing creds
debug1: fd 7 setting O_NONBLOCK
debug1: fd 9 setting O_NONBLOCK
debug1: channel 0: rcvd eof
debug1: channel 0: output open -> drain
debug1: channel 0: obuf empty
debug1: channel 0: output drain -> closed
debug1: channel 0: close_write
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 2145
debug1: session_exit_message: session 0 channel 0 pid 2145
debug1: session_exit_message: release channel 0
debug1: channel 0: read failed
debug1: channel 0: input open -> drain
debug1: channel 0: close_read
debug1: channel 0: input: no drain shortcut
debug1: channel 0: ibuf empty
debug1: channel 0: input drain -> closed
debug1: channel 0: send eof
debug1: session_free: session 0 pid 2145
debug1: channel 0: read<=0 rfd 7 len 0
debug1: channel 0: read failed
error: channel 0: internal error: we do not read, but chan_read_failed for
istate 8
debug1: channel 0: closing efd 9
debug1: channel 0: send close
debug1: channel 0: rcvd close
debug1: channel 0: full closed2
debug1: channel_free: channel 0: status: The following connections are
open:
  #0 server-session (t4 r0 i8/0 o128/0 fd 7/7)

Connection closed by remote host.
debug1: Calling cleanup 0x805b700(0x0)
debug1: Calling cleanup 0x80509d0(0x0)
debug1: Calling cleanup 0x8061690(0x0)
-----

----- scp -----
# scp -P 2022 -v empty.file pekkas at netcore.fi:~/
Executing: host netcore.fi, user pekkas, command scp -v -t ~/
SSH Version OpenSSH-2.1, protocol versions 1.5/2.0.
Compiled with SSL (0x0090581f).
debug: Reading configuration data /etc/ssh/ssh_config
debug: ssh_connect: getuid 0 geteuid 0 anon 0
debug: Connecting to netcore.fi [193.94.160.1] port 2022.
debug: Connection established.
debug: Remote protocol version 1.99, remote software version
OpenSSH_2.3.0p1
Enabling compatibility mode for protocol 2.0
debug: Local version string SSH-2.0-OpenSSH-2.1
debug: send KEXINIT
debug: done
debug: wait KEXINIT
debug: got
kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug: got kexinit: ssh-dss
debug: got
kexinit: 3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes128-cbc,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug: got
kexinit: 3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes128-cbc,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug: got kexinit: hmac-sha1,hmac-md5,hmac-ripemd160 at openssh.com
debug: got kexinit: hmac-sha1,hmac-md5,hmac-ripemd160 at openssh.com
debug: got kexinit: none,zlib
debug: got kexinit: none,zlib
debug: got kexinit: 
debug: got kexinit: 
debug: first kex follow: 0 
debug: reserved: 0 
debug: done
debug: kex: server->client blowfish-cbc hmac-sha1 none
debug: kex: client->server blowfish-cbc hmac-sha1 none
debug: Sending SSH2_MSG_KEXDH_INIT.
debug: bits set: 511/1024
debug: Wait SSH2_MSG_KEXDH_REPLY.
debug: Got SSH2_MSG_KEXDH_REPLY.
debug: keytype ssh-dss
debug: keytype ssh-dss
debug: Host 'netcore.fi' is known and matches the DSA host key.
debug: bits set: 516/1024
debug: len 55 datafellows 0
debug: dsa_verify: signature correct
debug: Wait SSH2_MSG_NEWKEYS.
debug: GOT SSH2_MSG_NEWKEYS.
debug: send SSH2_MSG_NEWKEYS.
debug: done: send SSH2_MSG_NEWKEYS.
debug: done: KEX2.
debug: send SSH2_MSG_SERVICE_REQUEST
debug: service_accept: ssh-userauth
debug: got SSH2_MSG_SERVICE_ACCEPT
debug: authentications that can continue: publickey,password
debug: key does not exist: /root/.ssh/id_dsa
pekkas at netcore.fi's password: 
debug: ssh-userauth2 successfull
debug: fd 4 setting O_NONBLOCK
debug: fd 5 setting O_NONBLOCK
debug: fd 6 setting O_NONBLOCK
debug: channel 0: new [client-session]
debug: send channel open 0
debug: Entering interactive session.
debug: callback start
debug: client_init id 0 arg 0
debug: Sending command: scp -v -t ~/
debug: client_set_session_ident: id 0
debug: callback done
debug: channel 0: open confirm rwindow 0 rmax 16384
debug: channel 0: rcvd adjust 32768
debug: channel 0: rcvd ext data 201
Sending file modes: C0644 0 empty.file
Environment:
  USER=pekkas
  LOGNAME=pekkas
  HOME=/home/pekkas
  PATH=/usr/local/bin:/bin:/usr/bin:/usr/X11R6/bin
  MAIL=/var/spool/mail/pekkas
  SHELL=/bin/bash
  SSH_CLIENT=x.y.z.w 1336 2022
debug: channel 0: written 201 to efd 6
debug: channel 0: send data len 19
empty.file           100% |**************************************|     0
--:-- ETA
debug: channel 0: send data len 1
debug: channel 0: read<=0 rfd 4 len 0[root at gap /share/redhat-6.2/extra] # 
debug: channel 0: read failed
debug: channel 0: input open -> drain
debug: channel 0: close_read
debug: channel 0: input: no drain shortcut
debug: channel 0: ibuf empty
debug: channel 0: input drain -> closed
debug: channel 0: send eof
debug: callback start
debug: client_input_channel_req: rtype exit-status reply 0
debug: callback done
debug: channel 0: rcvd eof
debug: channel 0: output open -> drain
debug: channel 0: rcvd close
debug: channel 0: obuf empty
debug: channel 0: output drain -> closed
debug: channel 0: close_write
debug: channel 0: send close
debug: channel 0: full closed2
debug: channel_free: channel 0: status: The following connections are
open:
  #0 client-session (t4 r0 i8/0 o128/0 fd -1/-1)

debug: !channel_still_open.
debug: Transferred: stdin 0, stdout 0, stderr 0 bytes in 0.3 seconds
debug: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
debug: Exit status 0
-----

HTH,
-- 
Pekka Savola                 "Tell me of difficulties surmounted, 
Pekka.Savola at netcore.fi      not those you stumble over and fall"