Subject: RE: libssh2 takes long time to disconnect from CoreFTP's SFTP service

RE: libssh2 takes long time to disconnect from CoreFTP's SFTP service

From: Xu, Qiang (FXSGSC) <Qiang.Xu_at_fujixerox.com>
Date: Fri, 19 Feb 2010 10:30:56 +0800

> -----Original Message-----
> From: libssh2-devel-bounces_at_cool.haxx.se
> [mailto:libssh2-devel-bounces_at_cool.haxx.se] On Behalf Of Peter Stuge
> Sent: Wednesday, February 17, 2010 7:07 PM
> To: libssh2-devel_at_cool.haxx.se
> Subject: Re: libssh2 takes long time to disconnect from
> CoreFTP's SFTP service
>
> Your snippet shows that libssh2 has a problem when disconnecting.
>
> It gets stuck just waiting and after a 10 minute delay the
> server (not libssh2) closes the connection. A timeout is
> probably configured in the server.

Thank you, Peter! You are right, again! Just found out that there is a setting of "idle timeout" in CoreFTP server, and it is 600 seconds by default. Please look at the attached screenshot.

And when this timeout is set to 1 sec, it is much faster.
=====================================================
qxu_at_durian(pts/3):~/opensrc/libssh2-1.2.4/example[119]$ ./sftpdir 13.xxx.xxx.xxx <user> <pass> /
...
[libssh2] 1.593013 SFTP: Data begin - Packet Length: 24
[libssh2] 1.593020 Socket: Error recving 16384 bytes to 0x843b648+0: 11
[libssh2] 1.593025 Conn: channel_read() got 24 of data from 0/0/0 [ul]
[libssh2] 1.593031 SFTP: Received packet 101 (len 24)
[libssh2] 1.593037 SFTP: Asking for 101 packet
[libssh2] 1.593042 SFTP: Got 101
[libssh2] 1.593054 Conn: Freeing channel 0/0 resources
[libssh2] 1.593060 Conn: Closing channel 0/0
=> libssh2_transport_write plain (5 bytes)
0000: 61 00 00 00 00 : a....
[libssh2] 1.593088 Socket: Sent 36/36 bytes at 0x843b4c0
=> libssh2_transport_write send() (36 bytes)
0000: 03 D3 A7 39 F5 63 94 10 E1 E9 21 14 70 F1 76 19 : ...9.c....!.p.v.
0010: DA 3E 49 9E 84 55 11 A2 D3 D8 8B DF 65 BB E6 3D : .>I..U......e..=
0020: C7 50 F6 A5 : .P..
[libssh2] 1.593112 Socket: Error recving 16384 bytes to 0x843b648+0: 11
[libssh2] 5.805839 Socket: Recved 68/16384 bytes to 0x843b648+0
=> libssh2_transport_read() raw (68 bytes)
0000: 73 C6 9B A4 32 E4 36 15 6A F1 BC 5F 64 8F 9C E3 : s...2.6.j.._d...
0010: B4 23 41 7D AE 41 D0 16 ED 99 7C 1A DA 3D 97 46 : .#A}.A....|..=.F
0020: B4 9B 63 4B A2 83 BB BD 4D 33 92 9C 26 00 71 2B : ..cK....M3..&.q+
0030: BB 48 53 04 50 B9 8E 2F 27 2C C2 90 38 81 00 C0 : .HS.P../',..8...
0040: FA E0 3C 66 : ..<f
=> libssh2_transport_read() plain (26 bytes)
0000: 01 00 00 00 02 00 00 00 0D 44 69 73 63 6F 6E 6E : .........Disconn
0010: 65 63 74 69 6E 67 00 00 00 00 : ecting....
[libssh2] 5.805912 Transport: Packet type 1 received, length=26
[libssh2] 5.805918 Transport: Disconnect(2): Disconnecting()
[libssh2] 5.805924 Failure Event: -13 - socket disconnect
[libssh2] 5.805933 Transport: Disconnecting: reason=11, desc=Normal Shutdown, Thank you for playing, lang=
=> libssh2_transport_write plain (51 bytes)
=====================================================
Still, I am wondering how this 1 sec timeout setting translates into 5 sec in disconnection. :-(

Anyway, it looks like a server's issue, not the problem of libssh2. By the way, libssh2 works perfectly well with OpenSSH and FreeFTPd, the other two Windows application that can provide SFTP service.
 
> Your debug log is very valuable to find the problem within
> libssh2, but I'm afraid that this problem will require some
> time to solve because the protocol state within libssh2 may
> need to be traced throughout the entire log in order to find
> the problem.
>
> It would be good to have this in the bug tracker so that it
> is not lost. Could you create a ticket for it? The component
> should probably be "protocol" even though the problem is only
> seen with SFTP so far.

Since it is due to the server's setting, I am not sure whether I shall continue to create a ticket for it.

> > Another word: FileZilla is using PSFTP.exe to do SFTP transactions,
> > and it is fast. Hope this helps.
>
> Yes that's right! There is no doubt that this is a problem in libssh2.

Just want to clarify that with the 600 sec idle timeout at the server's end, FileZilla connects fast, but the same delay appears when I tried to do anything further. Sorry that I didn't do thorough testing on FileZilla.

Thanks a lot for the help provided, Peter!
Xu Qiang

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

coreftp_timeout.jpg
Received on 2010-02-19