Hi everyone,
this is related to:
<http://sourceforge.net/mailarchive/message.php?msg_name=alpine.LRH.1.10.0810171246200.19702%40yvahk3.pbagnpgbe.fr>.
I decided to start a new thread, because the problem focus shifts toward the
handling of SSH_FXP_CLOSE command response in libssh2.
I'm still having problems using SFTP uploads using the multi interface. As you
might see in the thread linked above, libssh2 sometimes encounters a strange
response to an SSH_FXP_OPEN command. In case of success, the sftp specs say
that the result should be a handle to the opened file. What I get instead is
just a SSH_FXP_STATUS with result code 0, meaning "Success".
I added some logging to sftp.c, namely to the functions libssh2_sftp_open_ex(),
libssh2_sftp_write() and libssh2_sftp_close_handle(), that simply dumps out the
contents of the sftp protocol header for requests and responses. The result for
a failed transfer is as follows:
-----------------------<snip>-----------------------
open_packet: 00 00 00 48 03 00 00 00 01 00 00 00 33 2f 76 61 72 2f 77 77 77
2f 68 74 6d 6c 2f 74 65 73 74 66 69 6c 65 73 2f 61 77 75 72 66 2f 53 32 4e 65
74 2f 63 70 70 75 6e 69 74 5f 64 6c 6c 2e 64 6c 6c 00 00 00 1a 00 00 00 04 00
00 81 a4
open_packet_response: 66 00 00 00 01 00 00 00 04 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 02 00 00 00 04 00 00 00 00 00 00 00 00
00 00 00 00 00 00 40 00
write_packet_response: 65 00 00 00 02 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 03 00 00 00 04 00 00 00 00 00 00 00 00
00 00 40 00 00 00 40 00
write_packet_response: 65 00 00 00 03 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 04 00 00 00 04 00 00 00 00 00 00 00 00
00 00 80 00 00 00 40 00
write_packet_response: 65 00 00 00 04 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 05 00 00 00 04 00 00 00 00 00 00 00 00
00 00 c0 00 00 00 40 00
write_packet_response: 65 00 00 00 05 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 06 00 00 00 04 00 00 00 00 00 00 00 00
00 01 00 00 00 00 40 00
write_packet_response: 65 00 00 00 06 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 07 00 00 00 04 00 00 00 00 00 00 00 00
00 01 40 00 00 00 40 00
write_packet_response: 65 00 00 00 07 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 08 00 00 00 04 00 00 00 00 00 00 00 00
00 01 80 00 00 00 40 00
write_packet_response: 65 00 00 00 08 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 09 00 00 00 04 00 00 00 00 00 00 00 00
00 01 c0 00 00 00 40 00
write_packet_response: 65 00 00 00 09 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0a 00 00 00 04 00 00 00 00 00 00 00 00
00 02 00 00 00 00 40 00
write_packet_response: 65 00 00 00 0a 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0b 00 00 00 04 00 00 00 00 00 00 00 00
00 02 40 00 00 00 40 00
write_packet_response: 65 00 00 00 0b 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0c 00 00 00 04 00 00 00 00 00 00 00 00
00 02 80 00 00 00 40 00
write_packet_response: 65 00 00 00 0c 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 30 19 06 00 00 00 0d 00 00 00 04 00 00 00 00 00 00 00 00
00 02 c0 00 00 00 30 00
write_packet_response: 65 00 00 00 0d 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
close_packet: 00 00 00 0d 04 00 00 00 0e 00 00 00 04 00 00 00 00
open_packet: 00 00 00 44 03 00 00 00 0f 00 00 00 2f 2f 76 61 72 2f 77 77 77
2f 68 74 6d 6c 2f 74 65 73 74 66 69 6c 65 73 2f 61 77 75 72 66 2f 53 32 4e 65
74 2f 63 75 72 6c 6c 69 62 2e 64 6c 6c 00 00 00 1a 00 00 00 04 00 00 81 a4
open_packet_response: 65 00 00 00 0e 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
-----------------------</snip>----------------------
One should see a typical upload sequence of command requests and responses:
Open a file, write something to it and close it again and then continue with
the next file. The strange thing happens on the trailing three commands:
After the final data gets written, the command request SSH_FXP_CLOSE is sent.
But there is no response dumped (at least yet). Anyway, libcurl/libssh2
continues with the open request for the next file, expecting (in case of
success) a handle as result. But the response to the open command is
SSH_FXP_STATUS with result code 0 instead. This of cause leads to an error in
libcurl/libssh2, because this is truly unexpected behavior according to the
sftp specs.
If you examine the sequence ID's of the requests and responses, you quickly see
that the open_packet_response ID (0x0000000e) indeed matches the ID of the
close_packet sent before. So it seems, the protocol has gone out of sync
somehow. Maybe the response to the close command is delayed or something? I
don't know.
This dump is from a connection to an Ubuntu machine. I did another test with a
Windows-based machine. On that host, the situation is even worse: Nearly *every
single attempt* to upload a bunch of files shows this same error. Again, here's
the dump:
-----------------------<snip>-----------------------
open_packet: 00 00 00 3b 03 00 00 00 01 00 00 00 26 2f 74 65 73 74 66 69 6c
65 73 2f 61 77 75 72 66 2f 53 32 4e 65 74 2f 63 70 70 75 6e 69 74 5f 64 6c 6c
2e 64 6c 6c 00 00 00 1a 00 00 00 04 00 00 81 a4
open_packet_response: 66 00 00 00 01 00 00 00 04 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 02 00 00 00 04 00 00 00 00 00 00 00 00
00 00 00 00 00 00 40 00
write_packet_response: 65 00 00 00 02 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 03 00 00 00 04 00 00 00 00 00 00 00 00
00 00 40 00 00 00 40 00
write_packet_response: 65 00 00 00 03 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 04 00 00 00 04 00 00 00 00 00 00 00 00
00 00 80 00 00 00 40 00
write_packet_response: 65 00 00 00 04 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 05 00 00 00 04 00 00 00 00 00 00 00 00
00 00 c0 00 00 00 40 00
write_packet_response: 65 00 00 00 05 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 06 00 00 00 04 00 00 00 00 00 00 00 00
00 01 00 00 00 00 40 00
write_packet_response: 65 00 00 00 06 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 07 00 00 00 04 00 00 00 00 00 00 00 00
00 01 40 00 00 00 40 00
write_packet_response: 65 00 00 00 07 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 08 00 00 00 04 00 00 00 00 00 00 00 00
00 01 80 00 00 00 40 00
write_packet_response: 65 00 00 00 08 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 09 00 00 00 04 00 00 00 00 00 00 00 00
00 01 c0 00 00 00 40 00
write_packet_response: 65 00 00 00 09 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0a 00 00 00 04 00 00 00 00 00 00 00 00
00 02 00 00 00 00 40 00
write_packet_response: 65 00 00 00 0a 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0b 00 00 00 04 00 00 00 00 00 00 00 00
00 02 40 00 00 00 40 00
write_packet_response: 65 00 00 00 0b 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 40 19 06 00 00 00 0c 00 00 00 04 00 00 00 00 00 00 00 00
00 02 80 00 00 00 40 00
write_packet_response: 65 00 00 00 0c 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
write_packet: 00 00 30 19 06 00 00 00 0d 00 00 00 04 00 00 00 00 00 00 00 00
00 02 c0 00 00 00 30 00
write_packet_response: 65 00 00 00 0d 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
close_packet: 00 00 00 0d 04 00 00 00 0e 00 00 00 04 00 00 00 00
open_packet: 00 00 00 37 03 00 00 00 0f 00 00 00 22 2f 74 65 73 74 66 69 6c
65 73 2f 61 77 75 72 66 2f 53 32 4e 65 74 2f 63 75 72 6c 6c 69 62 2e 64 6c 6c
00 00 00 1a 00 00 00 04 00 00 81 a4
open_packet_response: 65 00 00 00 0e 00 00 00 00 00 00 00 07 53 75 63 63 65
73 73 00 00 00 00
-----------------------</snip>----------------------
I would like to try a patch: in libssh2_sftp_open_ex(), if in state
libssh2_NB_state_idle the response from the server is SSH_FXP_STATUS with
result code 0 and the ID of the previous command, I set sftp->open_state back
to libssh2_NB_state_sent and return NULL. This in effect discards the
misleading response and maybe I get the correct response for the open command
request in the next packet. Does that make sense?
My environment is:
MS-Windows XP
MS VisualStudio 2005
libcurl 7.19.0
libssh2 0.19.0_CVS as of 10-10-2008
c-ares 1.5.2
...
This is a real show-stopper for me, so I would appreciate very much, if we
could nail this bug down.
Cheers,
Andreas
--
Andreas Wurf <[EMAIL PROTECTED]>
Computer Scientist
Adobe Systems Engineering GmbH
Registergericht: Hamburg HRB 745 37, Geschäftsführer: Thomas Mührke
-------------------------------------------------------------------------
This SF.Net email is sponsored by the Moblin Your Move Developer's challenge
Build the coolest Linux based applications with Moblin SDK & win great prizes
Grand prize is a trip for two to an Open Source event anywhere in the world
http://moblin-contest.org/redirect.php?banner_id=100&url=/
_______________________________________________
libssh2-devel mailing list
libssh2-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/libssh2-devel
