Subject: Re: Command execution end

Re: Command execution end

From: Peter Stuge <peter_at_stuge.se>
Date: Tue, 4 Aug 2009 17:31:17 +0200

vti wrote:
> > here is a trace log in attachment. I am trying to run
> > '/bin/mkdir /tmp/foo'.
>
> And attachment :)

..

Here you try to close:

> [libssh2] 0.546703 Conn: Writing 0 bytes on channel 0/0, stream #0
> [libssh2] 0.546703 Conn: Writing 0 bytes on channel 0/0, stream #0
> Closing channel
> Closing channel
> Sending EOF
> Sending EOF
> [libssh2] 0.546883 Conn: Sending EOF on channel 0/0
> [libssh2] 0.546883 Conn: Sending EOF on channel 0/0
> => libssh2_transport_write plain (5 bytes)
> => libssh2_transport_write plain (5 bytes)
> 0000: 0000: 60 60 00 00 00 00 00 00 00 00 ``........

But libssh2 sends _CHANNEL_EOF instead of _CHANNEL_CLOSE. Hm?

..

Then, we wait for _CHANNEL_EOF from peer:

> Waiting for EOF
> Waiting for EOF
> [libssh2] 0.548208 Conn: Awaiting close of channel 0/0
> [libssh2] 0.548208 Conn: Awaiting close of channel 0/0
..

But there is still some more data:

> => libssh2_transport_read() plain (28 bytes)
> 0000: 5e 00 00 00 00 00 00 00 13 2f 62 69 6e 2f 6d 6b ^......../bin/mk
> 0010: 64 69 72 20 2f 74 6d 70 2f 66 6f 6f dir /tmp/foo
> [libssh2] 0.551448 Transport: Packet type 94 received, length=28
> [libssh2] 0.551454 Conn: 19 bytes packet_add() for 0/0/0
> => libssh2_transport_read() plain (13 bytes)
> 0000: 5e 00 00 00 00 00 00 00 04 0d 0a 0d 0a ^............
> [libssh2] 0.551502 Transport: Packet type 94 received, length=13
> [libssh2] 0.551506 Conn: 4 bytes packet_add() for 0/0/0

But after that, there's the _CHANNEL_EOF:

> => libssh2_transport_read() plain (5 bytes)
> 0000: 60 00 00 00 00 `....
> [libssh2] 0.551735 Transport: Packet type 96 received, length=5
> [libssh2] 0.551739 Conn: EOF received for channel 0/0
> Waiting for channel to close
> [libssh2] 0.551747 Failure Event: -34 - libssh2_channel_wait_closed() invoked when channel is not in EOF state

The above error doesn't make much sense. The _CHANNEL_EOF was just
received, so the channel should be in EOF state.

> [libssh2] 0.551752 Conn: Freeing channel 0/0 resources
> [libssh2] 0.551756 Conn: Closing channel 0/0

libssh2 sends _CHANNEL_CLOSE:

> => libssh2_transport_write plain (5 bytes)
> 0000: 61 00 00 00 00 a....
..

And gets one back:

> => libssh2_transport_read() plain (5 bytes)
> 0000: 61 00 00 00 00 a....
> [libssh2] 0.551941 Transport: Packet type 97 received, length=5
> [libssh2] 0.551946 Conn: Close received for channel 0/0

Now the channel seems to be closed, even if there were some trouble
with the EOFs.

The rest is just a big mess, I don't understand why there are writes
to a channel which has been closed.

> [libssh2] 0.551950 Transport: Looking for packet of type: 94
> [libssh2] 0.551953 Transport: Looking for packet of type: 94
> [libssh2] 0.551957 Transport: Looking for packet of type: 94
> [libssh2] 0.551961 Transport: Looking for packet of type: 95
> .......
> => libssh2_transport_read() plain (28 bytes)
> 0000: 5e 00 00 00 00 00 00 00 13 2f 62 69 6e 2f 6d 6b ^......../bin/mk
> 0010: 64 69 72 20 2f 74 6d 70 2f 66 6f 6f dir /tmp/foo
> [libssh2] 0.551448 Transport: Packet type 94 received, length=28
> [libssh2] 0.551454 Conn: 19 bytes packet_add() for 0/0/0
> => libssh2_transport_read() plain (13 bytes)
> 0000: 5e 00 00 00 00 00 00 00 04 0d 0a 0d 0a ^............
> [libssh2] 0.551502 Transport: Packet type 94 received, length=13
> [libssh2] 0.551506 Conn: 4 bytes packet_add() for 0/0/0
> => libssh2_transport_read() raw (72 bytes)
> 0000: d9 ac 14 cc 9a 85 ba fc f2 89 37 48 6b dd 15 ea ..........7Hk...
> 0010: f8 8d 98 ac 80 bc 7c e4 39 de 00 8e 63 66 3a b4 ......|.9...cf:.
> 0020: 8a 33 ae 9b d4 27 fc e3 66 5b 22 31 de ea e7 69 .3...'..f["1...i
> 0030: 77 fe c8 c2 43 6a 27 a9 1c b8 00 92 cf 9e 5e 2d w...Cj'.......^-
> 0040: 7a 11 82 09 91 6b 09 3f z....k.?
> => libssh2_transport_read() plain (5 bytes)
> 0000: 60 00 00 00 00 `....
> [libssh2] 0.551735 Transport: Packet type 96 received, length=5
> [libssh2] 0.551739 Conn: EOF received for channel 0/0
> Waiting for channel to close
> [libssh2] 0.551747 Failure Event: -34 - libssh2_channel_wait_closed() invoked when channel is not in EOF state
> [libssh2] 0.551752 Conn: Freeing channel 0/0 resources
> [libssh2] 0.551756 Conn: Closing channel 0/0
> => libssh2_transport_write plain (5 bytes)
> 0000: 61 00 00 00 00 a....
> => libssh2_transport_write send() (36 bytes)
> 0000: c4 db 9e c3 ff 72 bd 05 ce 45 85 5b 37 a0 ab 5b .....r...E.[7..[
> 0010: 26 a4 3a ea 8e 41 77 26 7b ae 14 ab 4f b6 33 08 &.:..Aw&{...O.3.
> 0020: 83 01 13 2b ...+
> => libssh2_transport_read() plain (5 bytes)
> 0000: 61 00 00 00 00 a....
> [libssh2] 0.551941 Transport: Packet type 97 received, length=5
> [libssh2] 0.551946 Conn: Close received for channel 0/0
> [libssh2] 0.551950 Transport: Looking for packet of type: 94
> [libssh2] 0.551953 Transport: Looking for packet of type: 94
> [libssh2] 0.551957 Transport: Looking for packet of type: 94
> [libssh2] 0.551961 Transport: Looking for packet of type: 95
> [libssh2] 0.552045 Transport: Disconnecting: reason=11, desc=Normal Shutdown, Thank you for playing, lang=
> [libssh2] 0.552045 Transport: Disconnecting: reason=11, desc=Normal Shutdown, Thank you for playing, lang=
> => libssh2_transport_write plain (51 bytes)
> => libssh2_transport_write plain (51 bytes)
> 0000: 0000: 01 01 00 00 00 00 00 00 0b 0b 00 00 00 00 00 00 26 26 4e 4e 6f 6f 72 72 6d 6d 61 61 6c 6c 20 20 ................&&NNoorrmmaall
>
> 0010: 0010: 53 53 68 68 75 75 74 74 64 64 6f 6f 77 77 6e 6e 2c 2c 20 20 54 54 68 68 61 61 6e 6e 6b 6b 20 20 SShhuuttddoowwnn,, TThhaannkk
>
> 0020: 0020: 79 79 6f 6f 75 75 20 20 66 66 6f 6f 72 72 20 20 70 70 6c 6c 61 61 79 79 69 69 6e 6e 67 67 00 00 yyoouu ffoorr ppllaayyiinngg..
>
> 0030: 0030: 00 00 00 00 00 00 ......
>
> => libssh2_transport_write send() (84 bytes)
> => libssh2_transport_write send() (84 bytes)
> 0000: 0000: 79 79 43 43 01 01 d4 d4 a0 a0 7e 7e 10 10 27 27 a0 a0 d1 d1 8d 8d 9a 9a 8d 8d d8 d8 af af a0 a0 yyCC......~~..'........
> 0010: 0e 83 f6 57 5e d6 03 ed 4a fb 06 22 22 60 11 0e ...W^...J..""`..
> 0020: 5e 0c b3 48 58 9a d0 13 d4 37 ab 18 36 79 2e b2 ^..HX....7..6y..
> 0030: 79 52 a0 50 b9 9b 4a 13 77 8a e8 6e fb 46 f2 74 yR.P..J.w..n.F.t
> 0040: a4 ba a1 8c 7a a1 d2 c4 28 4e fc 1e ca 7e bf 53 ....z...(N...~.S
> 0050: 80 d1 fc cb ....
> [libssh2] 0.554083 Transport: Freeing session resource
> '........
> 0010: 0e 83 f6 57 5e d6 03 ed 4a fb 06 22 22 60 11 0e ...W^...J..""`..
> 0020: 5e 0c b3 48 58 9a d0 13 d4 37 ab 18 36 79 2e b2 ^..HX....7..6y..
> 0030: 79 52 a0 50 b9 9b 4a 13 77 8a e8 6e fb 46 f2 74 yR.P..J.w..n.F.t
> 0040: a4 ba a1 8c 7a a1 d2 c4 28 4e fc 1e ca 7e bf 53 ....z...(N...~.S
> 0050: 80 d1 fc cb ....
> [libssh2] 0.554083 Transport: Freeing session resource

//Peter
_______________________________________________
libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
Received on 2009-08-04