Subject: Regression: Unable to send FXP_CLOSE command

Regression: Unable to send FXP_CLOSE command

From: Mark Riordan <mriordan_at_ipswitch.com>
Date: Tue, 28 Dec 2010 19:11:59 -0600

The latest libssh2 often returns the error
"Unable to send FXP_CLOSE command"
from libssh2_sftp_close(sftp_handle) when it's called after a download.
This is because in sftp_close_handle, after this line:

        rc = _libssh2_channel_write(channel, 0, handle->close_packet,
                                    packet_len);

the code sees that rc is greater than packet_len.

In all cases that I've seen, the file been downloaded correctly.

This seems to be a timing problem because, unfortunately,
I haven't been able to reproduce the problem with full tracing.

I have been able to reproduce it with limited tracing; my trace ends with:

[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: 160 bytes packet_add() for 0/0/0
[libssh2] 1.851175 Conn: 160 bytes packet_add() for 0/0/0
[libssh2] 1.851175 Conn: 160 bytes packet_add() for 0/0/0
[libssh2] 1.851175 Conn: 160 bytes packet_add() for 0/0/0
[libssh2] 1.851175 Conn: 160 bytes packet_add() for 0/0/0
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 1506 of data from 0/0/0 [ul]
[libssh2] 1.851175 Conn: channel_read() got 503 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 2009
[libssh2] 1.851175 Conn: channel_read() got 2009 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 2009)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 1645
[libssh2] 1.851175 Conn: channel_read() got 1645 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 103 (len 1645)
[libssh2] 1.851175 SFTP: recv packet
[libssh2] 1.851175 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 1.851175 SFTP: Data begin - Packet Length: 28
[libssh2] 1.851175 Conn: channel_read() got 28 of data from 0/0/0
[libssh2] 1.851175 SFTP: Received packet 101 (len 28)
[libssh2] 1.851175 SFTP: Closing handle
[libssh2] 1.851175 Failure Event: -7 - Unable to send FXP_CLOSE command
[libssh2] 1.851175 Conn: Freeing channel 0/0 resources
[libssh2] 1.851175 Conn: Sending EOF on channel 0/0
[libssh2] 1.851175 Conn: Closing channel 0/0
[libssh2] 1.851175 Conn: 128 bytes packet_add() for 0/0/0

(It's interesting that the "Received packet" messages nearly always
list packet 103. The only exceptions are the first, second, and last.)

Should I log a bug in Trac, even though the problem doesn't occur
in the released version?

Let me know what additional info you want.

Thanks.

Mark R

_______________________________________________
libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
Received on 2010-12-29