Subject: Re: Command execution end

Re: Command execution end

From: vti <viacheslav.t_at_gmail.com>
Date: Tue, 4 Aug 2009 17:41:43 +0200

2009/8/4 Peter Stuge <peter_at_stuge.se>:
> 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

Here is a demo program. See line #103 where sleep(2) is commented, without it it
doesn't work of course. There is also a trace log.

_______________________________________________
libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel

Received on 2009-08-04