Subject: Re: [PATCH] Follow RFC4253 section 11.4

Re: [PATCH] Follow RFC4253 section 11.4

From: Peter Stuge <peter_at_stuge.se>
Date: Thu, 1 Mar 2012 20:20:55 +0100

Steven Dake wrote:
> >> I was getting 1 or 2 3's and thousands of 82s in a 12 hour run.
> >> The 82s were in response to the keep alive, not sure what
> >> triggered the 3s.
> >
> > So run with full tracing enabled and stop when you see a 3 packet.

I cut the start of the trace.

> [libssh2] 0.717236 Transport: Requesting userauth service
> => libssh2_transport_write plain (17 bytes)
> 0000: 05 00 00 00 0C 73 73 68 2D 75 73 65 72 61 75 74 : .....ssh-useraut
> 0010: 68 : h
> [libssh2] 0.717281 Socket: Sent 52/52 bytes at 0x9c0128
> => libssh2_transport_write send() (52 bytes)
> 0000: 1C A5 D1 20 B4 FB 41 AB 34 9E 16 FD 21 1C AB 12 : ... ..A.4...!...
> 0010: DE 3F 46 05 6F BB 4B 85 35 CC 19 2C C6 27 28 8D : .?F.o.K.5..,.'(.
> 0020: 82 EE 5B 19 B7 92 E3 40 C3 AF F8 3A F6 E4 27 62 : ..[....@...:..'b
> 0030: 24 68 F2 C6 : $h..
> [libssh2] 0.717299 Transport: Looking for packet of type: 6
> [libssh2] 0.767461 Socket: Recved 52/16384 bytes to 0x9bc0e8+0
> => libssh2_transport_read() raw (52 bytes)
> 0000: 3D 54 C7 23 36 70 0B AA 74 E4 2B F0 63 D1 9D B8 : =T.#6p..t.+.c...
> 0010: D6 D5 43 7D 9B 04 18 03 79 3C D5 3D F0 08 16 11 : ..C}....y<.=....
> 0020: 7C 2B AC DD 03 C3 7E 2C 13 72 04 C5 12 0E 46 B3 : |+....~,.r....F.
> 0030: EE B4 89 F7 : ....
> => libssh2_transport_read() plain (17 bytes)
> 0000: 06 00 00 00 0C 73 73 68 2D 75 73 65 72 61 75 74 : .....ssh-useraut
> 0010: 68 : h
> [libssh2] 0.767573 Transport: Packet type 6 received, length=17
> [libssh2] 0.767579 Transport: Looking for packet of type: 6

Up until here there's no surprise.

> => libssh2_transport_write plain (27 bytes)
> 0000: 50 00 00 00 15 6B 65 65 70 61 6C 69 76 65 40 6C : P....keepalive_at_l
> 0010: 69 62 73 73 68 32 2E 6F 72 67 00 : ibssh2.org.
> [libssh2] 0.767635 Socket: Sent 68/68 bytes at 0x9c0128
> => libssh2_transport_write send() (68 bytes)
> 0000: DC 4B 03 4D D6 24 FB 86 84 81 CE 96 CB 73 28 C3 : .K.M.$.......s(.
> 0010: 62 2F 77 2B 28 47 B3 85 57 82 83 89 48 9A 4B 2C : b/w+(G..W...H.K,
> 0020: F7 CB A6 EF 94 E9 AA 5B CA 7C 4F B9 49 09 7B FC : .......[.|O.I.{.
> 0030: DF 22 C0 7C 0D A5 3B CF 72 C6 E1 95 0B 23 66 AB : .".|..;.r....#f.
> 0040: 79 E9 46 14 : y.F.

Here, libssh2 sends a SSH_MSG_GLOBAL_REQUEST.

"Note that both the client and server MAY send global requests at any
time, and the receiver MUST respond appropriately."

Taking apart the packet:

50 = SSH_MSG_GLOBAL_REQUEST
request name = 21 bytes "keepalive_at_libssh2.org"
want reply = 0

"The recipient will respond to this message with
SSH_MSG_REQUEST_SUCCESS or SSH_MSG_REQUEST_FAILURE if 'want reply' is
TRUE."

So there should be no response, and libssh2 moves on.

> [libssh2] 0.767690 Userauth: Loading public key file: /var/lib/pacemaker-cloud/keys/assy-wordpress-mysql-F16.pub
> [libssh2] 0.771962 Userauth: Attempting publickey authentication
> => libssh2_transport_write plain (335 bytes)
> 0000: 32 00 00 00 04 72 6F 6F 74 00 00 00 0E 73 73 68 : 2....root....ssh
> 0010: 2D 63 6F 6E 6E 65 63 74 69 6F 6E 00 00 00 09 70 : -connection....p
> 0020: 75 62 6C 69 63 6B 65 79 00 00 00 00 07 73 73 68 : ublickey.....ssh
> 0030: 2D 72 73 61 00 00 01 17 00 00 00 07 73 73 68 2D : -rsa........ssh-
> 0040: 72 73 61 00 00 00 03 01 00 01 00 00 01 01 00 AD : rsa.............
> 0050: 32 B0 7F 2D 20 7A 09 3B 8B CE 62 3D 4F 3D EC D4 : 2..- z.;..b=O=..
> 0060: EC 78 C3 12 E2 B3 29 FF B5 40 2D 57 23 DF 4F 14 : .x....).._at_-W#.O.
> 0070: 78 8F 96 F4 3B 9F 50 B6 DF D5 CF 26 39 99 70 D2 : x...;.P....&9.p.
> 0080: 4B 03 5C CA 0E D9 F4 3F 4C 56 68 F1 1F C4 93 08 : K.\....?LVh.....
> 0090: C8 72 1C EF 4B DD 58 88 55 13 04 26 4C 0B 2D 78 : .r..K.X.U..&L.-x
> 00a0: D0 A5 1F 60 34 AF A2 C7 D4 78 31 A1 9C A2 9C F1 : ...`4....x1.....
> 00b0: 89 4A 09 86 8C 07 EC C5 3D 72 02 E9 FB 97 F0 E5 : .J......=r......
> 00c0: 08 B3 17 43 94 97 E9 46 8B 59 72 40 82 84 94 1A : ...C...F.Yr@....
> 00d0: FD 41 C4 57 BA E6 10 17 05 9B 45 22 84 77 F0 47 : .A.W......E".w.G
> 00e0: 41 46 7F 6B 17 39 2F 43 7C 1B FB 48 DA 92 CF 51 : AF.k.9/C|..H...Q
> 00f0: 4D 15 C3 8C EF FC 12 BA 22 F0 28 45 3F C9 45 90 : M.......".(E?.E.
> 0100: C8 D5 17 3D 50 A2 DB B7 0C 64 4B AD 72 9B D9 10 : ...=P....dK.r...
> 0110: 48 51 D8 CC B8 12 10 5C B0 F1 F4 CC 37 CE 40 BF : HQ.....\....7.@.
> 0120: 66 19 F2 98 EE B5 08 57 7A AA 09 E9 A5 A3 05 CB : f......Wz.......
> 0130: DD 40 9D F3 69 53 91 50 FF 83 F4 50 13 C0 45 CF : .@..iS.P...P..E.
> 0140: B3 37 DB 51 B0 DE 0D 6E 53 DB 47 23 19 87 7B : .7.Q...nS.G#..{
> [libssh2] 0.772107 Socket: Sent 372/372 bytes at 0x9c0128
> => libssh2_transport_write send() (372 bytes)
> 0000: 53 41 16 2A 93 65 AC 8D 39 F7 98 09 73 DB 53 79 : SA.*.e..9...s.Sy
> 0010: 87 E8 37 9D 0C 47 3C F5 FB E4 45 0E 46 7A 8C 97 : ..7..G<...E.Fz..
> 0020: 8A B5 1B 0C 30 AB A0 A1 CF 5B DF 13 54 7C 97 6F : ....0....[..T|.o
> 0030: 0A 21 05 E3 A9 94 BC 79 EF 38 78 EE 06 13 51 24 : .!.....y.8x...Q$
> 0040: 1B 08 EE A4 28 45 E0 EF BE 09 4E DE 5E 9C EA DD : ....(E....N.^...
> 0050: 77 17 1F 33 A8 16 2A 21 24 AE 08 11 78 F1 F2 21 : w..3..*!$...x..!
> 0060: F0 42 38 CD F1 57 F6 24 EF 4B 3F 8E FF 70 C7 1B : .B8..W.$.K?..p..
> 0070: FC BE A0 AC 3D D3 62 D5 04 21 CB DB BC BC AE F6 : ....=.b..!......
> 0080: FA 56 DE D7 63 CC 22 ED D1 3B 57 8C 8B 58 0B 66 : .V..c."..;W..X.f
> 0090: BE FB DE C7 4F 5D 7C CF 56 4D C4 C7 16 D6 FA 4E : ....O]|.VM.....N
> 00a0: A2 2F D7 A4 BF D9 9B F3 03 2B 13 75 8B 17 A2 E2 : ./.......+.u....
> 00b0: 96 C3 FD 71 AC 6A 41 1A 4C E2 E4 3B 3E 5F D5 D4 : ...q.jA.L..;>_..
> 00c0: 9F 2F F5 C6 34 71 A4 E7 F9 A4 9F 9D FE DD 63 A7 : ./..4q........c.
> 00d0: 66 D3 C8 91 5A A5 EA C6 D3 70 E1 77 1B 3B 60 1D : f...Z....p.w.;`.
> 00e0: BA EB 8A 24 D2 DB A4 79 7D AC 4F 37 55 B1 0C 20 : ...$...y}.O7U..
> 00f0: 0B BA 26 BE DB C6 F9 2E 28 65 28 E7 D8 74 63 A5 : ..&.....(e(..tc.
> 0100: 3C F3 DB 0D 1D 3F 12 0F 1E 5A 16 08 4A 5D 8B 83 : <....?...Z..J]..
> 0110: 44 5A F8 07 02 3C 11 6F D7 56 F8 59 D0 C7 AA 0B : DZ...<.o.V.Y....
> 0120: 7E 00 51 20 01 D7 3B DD 31 1D 50 0A AD A1 64 BB : ~.Q ..;.1.P...d.
> 0130: D3 25 DA 6F 34 45 06 54 85 DE B8 86 32 AB CF E4 : .%.o4E.T....2...
> 0140: 02 47 0E 3F 59 3B 70 66 9D F7 37 CC 50 E8 E3 58 : .G.?Y;pf..7.P..X
> 0150: DC 55 04 21 D9 A6 DC A2 1E C5 E4 99 58 02 30 C6 : .U.!........X.0.
> 0160: D9 75 2C B6 DB 26 6E 11 8A 84 64 41 DF DD 89 DB : .u,..&n...dA....
> 0170: B6 EB AF 3D : ...=

Then libssh2 sends SSH_MSG_USERAUTH_REQUEST..

> [libssh2] 0.772198 Transport: Looking for packet of type: 52
> [libssh2] 0.772201 Transport: Looking for packet of type: 51
> [libssh2] 0.772204 Transport: Looking for packet of type: 60
> [libssh2] 0.772212 Socket: Recved 36/16384 bytes to 0x9bc0e8+0
> => libssh2_transport_read() raw (36 bytes)
> 0000: 90 0A B3 1D 2E DB 77 D4 8A 71 E8 9C E5 DC A8 DF : ......w..q......
> 0010: 27 A4 78 CF 89 31 E3 B9 26 65 09 28 16 11 E7 CD : '.x..1..&e.(....
> 0020: 95 FE CC CD : ....
> => libssh2_transport_read() plain (5 bytes)
> 0000: 03 00 00 00 04 : .....
> [libssh2] 0.772237 Transport: Packet type 3 received, length=5

..and gets back SSH_MSG_UNIMPLEMENTED.

It looks like your server has a problem.

To debug further, you could add a wait for SSH_MSG_UNIMPLEMENTED
after sending keepalive with want reply = 0, and see what happens.

//Peter
_______________________________________________
libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
Received on 2012-03-01