cURL / Mailing Lists / curl-library / Single Mail

curl-library

Re: libcurl + libevent2: Stalling if no data is received/written [new timeout patch]

From: Dirk Manske <dm_at_nonitor.de>
Date: Thu, 16 Sep 2010 15:13:18 +0200

Hi Daniel,

have you read the report I've written two weeks ago?

Your next release is comming, so I've checked if it got fixed.
According to my tests with latests version from git the bugs
are still alive.

But I've found a new detail, hiperfifo and connecting to nc -l -p 9999:

1284638114.184468 Adding easy 0x2257a80 to multi 0x222ec90 (http://127.0.0.1:9999/)
1284638114.184529 multi_timer_cb: Setting timeout to 1 ms
1284638114.191563 timer_cb called fd:-1 kind:1
* About to connect() to 127.0.0.1 port 9999 (#0)
* Trying 127.0.0.1... * connected
* Connected to 127.0.0.1 (127.0.0.1) port 9999 (#0)
* 0x2257a80 is at send pipe head!
> GET / HTTP/1.1
Host: 127.0.0.1:9999
Accept: */*

1284638114.191748 socket callback: s=7 e=0x2257a80 what=IN Adding data: IN
1284638114.191758 multi_timer_cb: Setting timeout to 4000 ms
1284638114.191762 timer_cb curl_multi_socket_action rc:0 running:1
1284638118.195561 timer_cb called fd:-1 kind:1
1284638118.195621 multi_timer_cb: Setting timeout to 2996 ms
1284638118.195635 timer_cb curl_multi_socket_action rc:0 running:1
1284638121.191575 timer_cb called fd:-1 kind:1
1284638121.191622 socket callback: s=7 e=0x2257a80 what=REMOVE
1284638121.191662 multi_timer_cb: Setting timeout to -1 ms
1284638121.191676 timer_cb curl_multi_socket_action rc:0 running:0
1284638121.191687 REMAINING: 0
1284638121.191702 DONE: http://127.0.0.1:9999/ => (28) msg:
* Connection #0 to host 127.0.0.1 left intact
1284638121.191870 timer_cb called fd:-1 kind:1
1284638121.191885 timer_cb curl_multi_socket_action rc:0 running:0

As already written the error message is missing, but I guess
more worse is what curl tells us:
* Connection #0 to host 127.0.0.1 left intact

I think curl should close that connection.
Or would that be a problem if pipeling is used?

And the second problem..

> With hiperfifo it's the same... but with a new side effect:
...
> Don't start 'nc -l -p 9999' yet, but ./hiperfifo
> and do 'echo http://127.0.0.1:9999/ >hiper.fifo'
...
> * Trying 127.0.0.1... * Connection refused
...
> Alright, connection refused, but where is the DONE message from
> hiperfifo...

I must correct me, that is not a new side effect. That bug happens
with 7.21.1 too. Here a new test run, with a different 2nd test:

1284638755.661834 Adding easy 0x2283a80 to multi 0x225ac90 (http://127.0.0.1:9999/)
1284638755.661875 multi_timer_cb: Setting timeout to 1 ms
1284638755.665061 timer_cb called fd:-1 kind:1
* About to connect() to 127.0.0.1 port 9999 (#0)
* Trying 127.0.0.1... * Connection refused
* couldn't connect to host
* Expire cleared
* Closing connection #0
1284638755.665320 multi_timer_cb: Setting timeout to -1 ms
1284638755.665336 timer_cb curl_multi_socket_action rc:0 running:0
1284638755.665353 timer_cb called fd:-1 kind:1
1284638755.665364 timer_cb curl_multi_socket_action rc:0 running:0

When a connection fails very early then the socket callback is not
called. Connection refused from a remote machine is ok:

1284639046.622480 Adding easy 0x22baa40 to multi 0x225ac90 (http://nonitor.de:22/)
1284639046.622521 multi_timer_cb: Setting timeout to 1 ms
1284639046.625078 timer_cb called fd:-1 kind:1
* 0x22baa40 is at send pipe head!
1284639046.625408 socket callback: s=7 e=0x22baa40 what=IN Adding data: IN
1284639046.625445 multi_timer_cb: Setting timeout to 4000 ms
1284639046.625458 timer_cb curl_multi_socket_action rc:0 running:1
1284639046.625718 socket callback: s=7 e=0x22baa40 what=REMOVE
* About to connect() to nonitor.de port 22 (#0)
* Trying 212.1.39.66... 1284639046.625835 socket callback: s=7 e=0x22baa40 what=OUT Adding data: OUT
* Connection refused
* Failed connect to nonitor.de:22; Connection refused
* Expire cleared
* Closing connection #0
1284639046.639017 socket callback: s=7 e=0x22baa40 what=REMOVE
1284639046.639046 multi_timer_cb: Setting timeout to -1 ms
1284639046.639060 REMAINING: 0
1284639046.639073 DONE: http://127.0.0.1:9999/ => (7) msg:couldn't connect to host
1284639046.639215 DONE: http://nonitor.de:22/ => (7) msg:Failed connect to nonitor.de:22; Connection refused
1284639046.639277 last transfer done, kill timeout

Now the callback is triggered and we get the DONE message(s) from hiperfifo.
Note that the error message of the remotely refused connection is more verbose
than the local one.

I would try to fix both problems, but until Monday I'm busy with
something totally different.

So long...
-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
Received on 2010-09-16