Re: SFTP read-ahead problem

[Aris Adamantiadis <aris@xxxxxxxxxxxx>]

Hi Tilo,

Awesome finding! That was a tricky bug you just found. I'll push your
patch in ASAP.

Aris
Le 31/07/15 14:29, Tilo Eckert a écrit :
> Hi,
>
> eventually I took the time to dig into the packet processing code and
> managed to find the bug that caused random "Short sftp packet!" errors.
>
> When there are multiple pending read requests, the OpenSSH server stuffs
> multiple SFTP data packets into one CHANNEL_DATA packet until 32KiB are
> full. As a result, SFTP packets may be split and sent as payload of
> multiple CHANNEL_DATA packets. At some point, the length field of the
> SFTP packet will be the splitting point. This is what sftp_packet_read()
> is unable to handle. It calls ssh_channel_read() with length 4 and
> expects to get 4 bytes, which ssh_channel_read() does not guarantee. In
> the split length field situation, less than 4 bytes are read which
> results in the aforementioned error.
>
> A patch is attached which reads the length field in a loop until 4 bytes
> are read.
>
> Tilo
>
> Am 08.06.2015 um 13:09 schrieb Tilo Eckert:
>> I used libssh 0.7.0 for my tests. The 0.6 branch from git has the same
>> issue. Of the 0.6.x source tarballs none of them compiles here (ArchLinux).
>>
>> Here is a verbose log where the sftp_close() does not get stuck (remote
>> host, run with N=1024):
>> https://paste.ee/p/A4N4i
>> and here it gets stuck (same host/file, N=128):
>> https://paste.ee/p/WoIeY
>>
>> Regards,
>> Tilo
>>
>> Am 08.06.2015 um 12:04 schrieb Aris Adamantiadis:
>>> Hi,
>>>
>>> I agree with your analysis. Which libssh version did you use ? Could you
>>> try again with 0.6.0 and tell us if the same happens ?
>>> Please attach verbose logs.
>>>
>>> Aris
>>>
>>> Le 08/06/15 11:46, Tilo Eckert a écrit :
>>>> Hi,
>>>>
>>>> I am trying to implement a simple read-ahead mechanism for reading large
>>>> files via SFTP using sftp_async_read_begin() and sftp_async_read(). On
>>>> the first attempt to read a 4096 bytes block, I request N times 4K, and
>>>> read the first 4K block. On successive reads, for each block read
>>>> another one is requested to keep N requests on the wire.
>>>>
>>>> The problem is: sftp_async_read() suddenly fails with the error message
>>>> "Short sftp packet!" after successfully reading a few hundred packets
>>>> when N is large enough and the server is running OpenSSH. For a remote
>>>> host over a 5 Mbit internet connection with 60ms latency, the issue
>>>> starts when requesting more than about 70 blocks. In my tests on GBit
>>>> LAN, the issue started for somewhat larger values of N.
>>>>
>>>> When I attempt to call sftp_async_read() or sftp_close() after the error
>>>> occurs, I can see from the libssh log that all requests are actually
>>>> fulfilled by the server (i.e. N * 4K are received by the socket). For
>>>> certain combinations of N and network connection, calls to these
>>>> functions also get stuck and never return. In other cases, closing fails
>>>> with "Unknown packet type 0".
>>>>
>>>> Here is a sample program that demonstrates the issue:
>>>> http://pastebin.com/gfiFKfDT
>>>>
>>>> I tested this with different OpenSSH versions between 6.0 and 6.8 on
>>>> Windows and Linux, and with freeSSHd on Windows. With all OpenSSH
>>>> versions, I get the described behavior. With freeSSHd, there are no
>>>> issues at all. I successfully tested it with up to N=4096 (i.e. 16 MiB
>>>> read-ahead).
>>>>
>>>> It looks to me like libssh starts to misinterpret packets under certain
>>>> conditions. Maybe someone with deeper insight can investigate this.
>>>>
>>>> Regards,
>>>> Tilo
>>>>
>>>
>>