Daniel Stenberg wrote:
> On Fri, 20 Mar 2009, Heiner Steven wrote:
>>> I've done quite a lot of tests with non-blocking and I've not seen this,
>>> and I've also got reports from others who've done the libcurl-based (~30)
>>> tests without experiencing this. It might indicate that the problem happens
>>> only in more specific situations, like with a particular server on a
>>> particular OS or something else...
>> This could be the case, but on the other hand version 0.18 and 1.0 both run
>> without problems on the same system.
>
> What other alternatives can you think of? Did you try this against other SFTP
> servers?
I tested with the local Linux OpenSSH server (5.1) and with a Solaris 10
server, also with OpenSSH 5.0.
>> I wonder what the error code "ERESTARTSYS" means, which recvfrom() returns
>> on the SIGQUIT signal.
>
> I'm personally more stunned by the fact it blocks in the first place. Why does
> it do so when set non-blocking?
>
> Anyway, can you build libssh2 debug-enabled and call libssh2_trace(~0) before
> the libssh2_sftp_init() call to give us a dump of debug info to look at?
This is the relevant part of the modified code:
--------------------------------------------------------------
/* No SFTP session: create a new one */
if (!(session = getsession(conn, url))) {
return NULL;
}
libssh2_trace(cp->session, ~0);
libssh2_session_set_blocking(cp->session, 0);
while (!(cp->sftp = libssh2_sftp_init(cp->session))) {
errmsg("DEBUG: libssh2_sftp_init failed: %d\n",
libssh2_session_last_errno(cp->session));
if (libssh2_session_last_errno(cp->session) != LIBSSH2SFTP_EAGAIN)
break;
sleep(1);
}
if (!cp->sftp) {
ssherrmsg(cp->session, "ERROR: could not initiate SFTP session");
return NULL;
}
--------------------------------------------------------------
And here is the (long) output with trace enabled:
--------------------------------------------------------------
scopy: DEBUG: getsession: authenticate_session succeeded; session=0x1a946b0
[libssh2] 0.286365 Conn: Setting blocking mode on session 0
[libssh2] 0.286376 SFTP: Initializing SFTP subsystem
[libssh2] 0.286379 Conn: Allocated new channel ID#0
[libssh2] 0.286381 Conn: Opening Channel - win 65536 pack 32768
=> libssh2_packet_write plain (24 bytes)
0000: 5a 00 00 00 07 73 65 73 73 69 6f 6e 00 00 00 00 Z....session....
0010: 00 01 00 00 00 00 80 00 ........
=> libssh2_packet_write send() (68 bytes)
0000: 63 74 08 ff f0 70 df 4f 0e 39 0a 91 9c d7 c4 b6 ct...p.O.9......
0010: e0 4b 21 46 b2 35 b2 8b bb 3b d9 01 b7 e1 29 f6 .K!F.5...;....).
0020: c9 10 74 4a 8d a3 b3 12 d4 bf 5c 61 bc 02 f7 df ..tJ......\a....
0030: f5 6f 2b 39 e6 58 bf e8 34 4f a6 89 80 d2 ee 6c .o+9.X..4O.....l
0040: 01 32 c4 1f .2..
[libssh2] 0.286437 Transport: Looking for packet of type: 91
[libssh2] 0.286440 Transport: Looking for packet of type: 92
[libssh2] 0.398886 Failure Event: -37 - Would block
[libssh2] 0.398906 Failure Event: -37 - Would block starting up channel
scopy: DEBUG: libssh2_sftp_init failed: -37
[libssh2] 1.399014 Transport: Looking for packet of type: 91
[libssh2] 1.399031 Transport: Looking for packet of type: 92
=> libssh2_packet_read() raw (52 bytes)
0000: c4 51 cc d4 39 64 50 66 91 2a 14 c1 8f e8 9a e9 .Q..9dPf.*......
0010: 80 3c e9 72 90 11 40 d7 1e 79 00 52 cd de b7 3f .<.r..@..y.R...?
0020: 8d a4 33 00 e2 fe 11 09 60 83 ce 31 24 b2 7d 2c ..3.....`..1$.},
0030: e5 f0 97 12 ....
=> libssh2_packet_read() plain (17 bytes)
0000: 5b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 80 [...............
0010: 00 .
[libssh2] 1.399115 Transport: Packet type 91 received, length=17
[libssh2] 1.399120 Transport: Looking for packet of type: 91
[libssh2] 1.399123 Conn: Connection Established - ID: 0/0 win: 0/65536 pack: 32768/32768
[libssh2] 1.399133 Conn: starting request(subsystem) on channel 0/0, message=sftp
=> libssh2_packet_write plain (27 bytes)
0000: 62 00 00 00 00 00 00 00 09 73 75 62 73 79 73 74 b........subsyst
0010: 65 6d 01 00 00 00 04 73 66 74 70 em.....sftp
=> libssh2_packet_write send() (68 bytes)
0000: 46 8e e2 29 80 a3 9c 7b b6 bc 4d 1b 31 e3 53 69 F..)...{..M.1.Si
0010: c5 58 61 84 1c 2f 73 58 2d ea bb e8 7e 5e 65 84 .Xa../sX-...~^e.
0020: 09 4d b5 0a 9b 42 ae 34 98 67 7d 39 39 4e bb 9d .M...B.4.g}99N..
0030: 3d 14 44 bb a9 ee 56 af 2b 17 9f 28 8a 27 e4 11 =.D...V.+..(.'..
0040: 62 a4 ab 25 b..%
[libssh2] 1.399220 Transport: Looking for packet of type: 99
[libssh2] 1.399223 Transport: Looking for packet of type: 100
[libssh2] 1.399809 Failure Event: -37 - Would block to request SFTP subsystem
scopy: DEBUG: libssh2_sftp_init failed: -37
[libssh2] 2.399944 Transport: Looking for packet of type: 99
[libssh2] 2.399962 Transport: Looking for packet of type: 100
=> libssh2_packet_read() raw (88 bytes)
0000: 26 7a 1d 75 4f fc 09 1e 9b 39 3d dd 9f 05 26 9d &z.uO....9=...&.
0010: 7f 9f d8 d5 54 0f f5 21 fa 25 7e 81 57 d8 d9 98 ...T..!.%~.W...
0020: 03 e4 04 42 13 06 6b ff e1 10 86 4d 99 d2 72 fa ...B..k....M..r.
0030: ba cb ef 88 dc dd f7 46 38 67 9c 2d 77 ae 31 f4 .......F8g.-w.1.
0040: dc 08 db 66 20 bd fb d5 98 eb e5 9b 4b 9b 63 f6 ...f .......K.c.
0050: cc a9 f4 dc ae d0 fe 4e .......N
=> libssh2_packet_read() plain (9 bytes)
0000: 5d 00 00 00 00 00 20 00 00 ]..... ..
[libssh2] 2.400058 Transport: Packet type 93 received, length=9
[libssh2] 2.400062 Conn: Window adjust received for channel 0/0, adding 2097152 bytes, new window_size=2097152
=> libssh2_packet_read() plain (5 bytes)
0000: 63 00 00 00 00 c....
[libssh2] 2.400081 Transport: Packet type 99 received, length=5
[libssh2] 2.400085 Transport: Looking for packet of type: 99
[libssh2] 2.400105 Conn: Setting channel 0/0 handle_extended_data mode to 1
[libssh2] 2.400108 SFTP: Sending FXP_INIT packet advertising version 3 support
[libssh2] 2.400110 Conn: Writing 9 bytes on channel 0/0, stream #0
[libssh2] 2.400113 Conn: Sending 9 bytes on channel 0/0, stream_id=0
=> libssh2_packet_write plain (18 bytes)
0000: 5e 00 00 00 00 00 00 00 09 00 00 00 05 01 00 00 ^...............
0010: 00 03 ..
=> libssh2_packet_write send() (52 bytes)
0000: 72 e5 8e 8e 7d d3 f2 a0 6d cf 23 67 7e 69 8a f8 r...}...m.#g~i..
0010: 1e 66 c3 d7 91 f9 ff cd 56 ec 96 d3 7b 90 7c 7b .f......V...{.|{
0020: 44 3b f4 ea 69 7f d6 c9 ee 77 fe 4b d0 f0 6c 94 D;..i...w.K..l.
0030: 15 54 9f 98 .T..
[libssh2] 2.400174 SFTP: Requiring packet 2 id 0
[libssh2] 2.400177 SFTP: Asking for 2 packet
[libssh2] 2.400179 SFTP: recv packet
[libssh2] 2.400181 Conn: channel_read() wants 4 bytes from channel 0/0 stream #0
[libssh2] 2.400184 Failure Event: -37 - Would block waiting for response from SFTP subsystem
scopy: DEBUG: libssh2_sftp_init failed: -37
[libssh2] 3.400283 SFTP: Requiring packet 2 id 0
[libssh2] 3.400302 SFTP: Asking for 2 packet
[libssh2] 3.400309 SFTP: recv packet
[libssh2] 3.400312 Conn: channel_read() wants 4 bytes from channel 0/0 stream #0
=> libssh2_packet_read() raw (148 bytes)
0000: fd 6e 0f 08 4f e2 cf 5e 9f bb 48 66 5f 85 cb d8 .n..O..^..Hf_...
0010: 81 80 12 91 6f 17 1a 74 24 0f 85 20 f9 38 a8 b4 ....o..t$.. .8..
0020: e5 02 b6 6d 26 32 af a2 bc 7d 6f cf 94 9d 7e 48 ...m&2...}o...~H
0030: 88 1c 88 56 34 e5 33 48 a8 88 eb b1 20 52 e2 df ...V4.3H.... R..
0040: 53 aa 4f 28 b8 1c 57 4b 72 39 96 5c 6c d2 29 c6 S.O(..WKr9.\l.).
0050: 96 ed 1a b0 15 d6 c3 05 6f 78 59 31 00 8c b3 fb ........oxY1....
0060: dd 2c 6f 44 71 6a 14 ef a7 7e 3c c0 7d 53 f5 6f .,oDqj...~<.}S.o
0070: 53 0d 25 f8 3b a6 11 38 a8 e0 0b da b9 12 45 47 S.%.;..8......EG
0080: 91 6c 14 f5 ff 6a 8e 75 00 36 dc 94 99 4d 5c 03 .l...j.u.6...M\.
0090: 91 75 a3 b3 .u..
=> libssh2_packet_read() plain (108 bytes)
0000: 5e 00 00 00 00 00 00 00 63 00 00 00 5f 02 00 00 ^.......c..._...
0010: 00 03 00 00 00 18 70 6f 73 69 78 2d 72 65 6e 61 ......posix-rena
0020: 6d 65 40 6f 70 65 6e 73 73 68 2e 63 6f 6d 00 00 me_at_openssh.com..
0030: 00 01 31 00 00 00 13 73 74 61 74 76 66 73 40 6f ..1....statvfs_at_o
0040: 70 65 6e 73 73 68 2e 63 6f 6d 00 00 00 01 32 00 penssh.com....2.
0050: 00 00 14 66 73 74 61 74 76 66 73 40 6f 70 65 6e ...fstatvfs_at_open
0060: 73 73 68 2e 63 6f 6d 00 00 00 01 32 ssh.com....2
[libssh2] 3.400461 Transport: Packet type 94 received, length=108
[libssh2] 3.400464 Conn: 99 bytes packet_add() for 0/0/0
[libssh2] 3.400468 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 3.400471 Conn: Adjusting window 39321600 bytes for data on channel 0/0
=> libssh2_packet_write plain (9 bytes)
0000: 5d 00 00 00 00 02 58 00 00 ].....X..
=> libssh2_packet_write send() (52 bytes)
0000: 13 90 b6 3f da 64 32 6d 0f 13 5a 3e 7c fe 94 bd ...?.d2m..Z>|...
0010: 06 e3 8b 77 36 53 8d 3a df 59 36 19 59 da 56 3a ...w6S.:.Y6.Y.V:
0020: 80 ee 5a ab c1 5e e4 26 5f 99 c9 14 6e 42 ba 50 ..Z..^.&_...nB.P
0030: 48 66 73 49 HfsI
[libssh2] 3.400551 Conn: channel_read() filled 4 adjusted 4
[libssh2] 3.400554 SFTP: Data begin - Packet Length: 95
[libssh2] 3.400557 Conn: channel_read() got 95 of data from 0/0/0 [ul]
[libssh2] 3.400560 SFTP: Received packet 2 (len 95)
[libssh2] 3.400563 SFTP: Asking for 2 packet
[libssh2] 3.400565 SFTP: Got 2
[libssh2] 3.400566 SFTP: Enabling SFTP version 3 compatability
[libssh2] 3.400569 Conn: Setting blocking mode on session 1
[libssh2] 3.400576 SFTP: Statting /tmp
[libssh2] 3.400578 Conn: Writing 17 bytes on channel 0/0, stream #0
[libssh2] 3.400581 Conn: Sending 17 bytes on channel 0/0, stream_id=0
=> libssh2_packet_write plain (26 bytes)
0000: 5e 00 00 00 00 00 00 00 11 00 00 00 0d 11 00 00 ^...............
0010: 00 00 00 00 00 04 2f 74 6d 70 ....../tmp
=> libssh2_packet_write send() (68 bytes)
0000: 3d 83 e5 ee 77 e1 c0 f0 d0 b1 43 27 e7 88 67 af =...w.....C'..g.
0010: da 00 9f 73 a9 ad 68 7e cb da 6e fb 7e 38 b0 b4 ...s..h~..n.~8..
0020: f5 02 a4 2f 42 1a 82 8f 90 a3 10 bf 36 5b 90 f3 .../B.......6[..
0030: 6b 1a 1f 30 55 e7 32 13 7b f4 f4 d8 c4 48 29 05 k..0U.2.{....H).
0040: f9 a9 66 bc ..f.
[libssh2] 3.400623 SFTP: Asking for 105 packet
[libssh2] 3.400626 SFTP: Asking for 101 packet
[libssh2] 3.400628 SFTP: recv packet
=> libssh2_packet_read() raw (84 bytes)
0000: b7 9e 87 0f 02 e1 92 03 26 10 ab b5 81 d1 b2 41 ........&......A
0010: 3a 60 28 0e 29 46 78 a9 34 e5 c2 9c 33 5e 94 ee :`(.)Fx.4...3^..
0020: 39 33 02 3a c8 ee 58 8f a1 41 c7 c6 4d 50 31 c5 93.:..X..A..MP1.
0030: 19 a6 bc f9 e0 4a 5a 03 3f 68 93 cb 73 23 39 8e .....JZ.?h..s#9.
0040: b4 eb 2b d4 ec 50 6a 99 25 35 89 0a ec 6c 25 fc ..+..Pj.%5...l%.
0050: 63 a5 8e 0d c...
=> libssh2_packet_read() plain (50 bytes)
0000: 5e 00 00 00 00 00 00 00 29 00 00 00 25 69 00 00 ^.......)...%i..
0010: 00 00 00 00 00 0f 00 00 00 00 00 00 05 d0 00 00 ................
0020: 00 00 00 00 00 00 00 00 43 ff 49 c5 16 e3 49 c6 ........C.I...I.
0030: 2f 5d /]
[libssh2] 3.437728 Transport: Packet type 94 received, length=50
[libssh2] 3.437731 Conn: 41 bytes packet_add() for 0/0/0
[libssh2] 3.437734 Conn: channel_read() got 4 of data from 0/0/0
[libssh2] 3.437736 SFTP: Data begin - Packet Length: 37
### [The session "hangs" here]
--------------------------------------------------------------
The problem could be related to the actions described by the
following output lines:
[libssh2] 3.400566 SFTP: Enabling SFTP version 3 compatability
[libssh2] 3.400569 Conn: Setting blocking mode on session 1
Heiner
------------------------------------------------------------------------------
Apps built with the Adobe(R) Flex(R) framework and Flex Builder(TM) are
powering Web 2.0 with engaging, cross-platform capabilities. Quickly and
easily build your RIAs with Flex Builder, the Eclipse(TM)based development
software that enables intelligent coding and step-through debugging.
Download the free 60 day trial. http://p.sf.net/sfu/www-adobe-com
_______________________________________________
libssh2-devel mailing list
libssh2-devel_at_lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/libssh2-devel
Received on 2009-03-22