On Wed, 27 Jan 2016, P. V. wrote: > Hi Damien, > > Thanks for your reply. I really appreciate you taking the time to > investigate this. > > I will try to clarify some things. > > > I'm not sure what you mean by "entering a key exchange without receiving > > a proper kexinit message" because key exchange is initiated by a kexinit > > message. Do you mean that method specific messages are accepted before > > KEXINIT? (I can't see how this can happen from looking at the code). > > Attached (log1) you find the OpenSSH debug log for a sequence in which > I manually send the sequence "SSH_MSG_KEXDH_INIT; SSH_MSG_KEXDH_INIT; > SSH_MSG_NEWKEYS". A normal key exchange sequence would be > "SSH_MSG_KEXINIT; SSH_MSG_KEXDH_INIT; SSH_MSG_NEWKEYS". Unless there > is an error in my code, it seems that OpenSSH does accept this anyway. > The log states: > > Jan 27 11:19:31 desktop sshd[4066]: debug1: SSH2_MSG_KEXINIT received [preauth] > while it didn't receive a KEXINIT but a KEXDH_INIT. > > Same goes for a sequence such as: "SSH_MSG_IGNORE; SSH_MSG_KEXDH_INIT; > SSH_MSG_NEWKEYS". Instead of receiving a KEXINIT, the server receives > an IGNORE but continues with the key exchange anyway. > > This only applies to the messages the server receives, it always > correctly sends an KEXINIT upon connection. I've added some debugging to ssh and sshd that might prove useful - they will not include the types they receive in debug output. > I sent the following message sequence to the server: "SSH_MSG_KEXINIT; > SSH_MSG_KEXDH_INIT; SSH_MSG_NEWKEYS; SSH_MSG_SERVICE_REQUEST; > SSH_MSG_NEWKEYS". It behaves normally up until the point that I > initiate a key re-exchange (last message). The SSH server returns an > SSH_MSG_UNIMPLEMENTED and closes the connection. Log2 gives the debug > output. You're right - I'll take a look at fixing this. It seems that the userauth code is clobbering the handlers for the KEX messages. > > It would be helpful to see debug messages from ssh/sshd for this case > > (well, all cases but this in particular). > > I sent the following sequence to the OpenSSH server. > > SSH_MSG_KEXINIT; > (server replies with SSH_MSG_KEXINIT) > SSH_MSG_KEXDH_INIT; > (server replies with SSH_MSG_KEXDH_REPLY) > SSH_MSG_NEWKEYS; > (server does not reply) > SSH_MSG_SERVICE_REQUEST; > (server replies with SSH_MSG_SERVICE_ACCEPT) > SSH_MSG_USERAUTH_REQUEST > (server replies with SSH_MSG_USERAUTH_SUCCESS and SSH_MSG_GLOBAL_REQUEST) > SSH_MSG_CHANNEL_OPEN > (server replies with SSH_MSG_CHANNEL_OPEN_CONFIRMATION) > > -- Now I do a rekey -- > SSH_MSG_KEXINIT; > (server replies with SSH_MSG_KEXINIT) > SSH_MSG_KEXDH_INIT; > (server replies with SSH_MSG_KEXDH_REPLY) > SSH_MSG_NEWKEYS; > (server does not reply) > > -- Now I close the channel -- > > SSH_MSG_CHANNEL_CLOSE > (server replies with SSH_MSG_CHANNEL_CLOSE and sends an SSH_MSG_DISCONNECT) > > The entire debug log can be found in the log4 attachment. It looks like the channel is being closed twice for some reason: Jan 27 11:47:32 desktop sshd[4673]: debug1: session_by_channel: session 0 channel 0 Jan 27 11:47:32 desktop sshd[4673]: debug1: session_close_by_channel: channel 0 child 0 Jan 27 11:47:32 desktop sshd[4673]: debug1: session_close: session 0 pid 0 Jan 27 11:47:32 desktop sshd[4673]: debug1: channel 0: free: server-session, nchannels 1 Jan 27 11:47:32 desktop sshd[4673]: channel_by_id: 0: bad id: channel free Jan 27 11:47:32 desktop sshd[4673]: Disconnecting: Received oclose for nonexistent channel 0. I think the extra debugging in git HEAD might help see what's going on here. You should see debug messages like: debug3: receive packet: type 98 debug3: receive packet: type 96 debug3: receive packet: type 97 debug3: send packet: type 97 among the other ones that should make the sequence of operations clearer. -d -d _______________________________________________ openssh-unix-dev mailing list openssh-unix-dev@xxxxxxxxxxx https://lists.mindrot.org/mailman/listinfo/openssh-unix-dev
