cURL / Mailing Lists / curl-library / Single Mail

curl-library

PHP/select/curl background fetch conflation

From: Peter Naulls <peter_at_chocky.org>
Date: Wed, 27 Mar 2013 12:01:45 -0700

First to avoid any confusion ;-) I'm an old school Linux/network programmer,
but I admit to being a bit rusty. I'm using latest curl git, and I can repeat
this on both Ubuntu 12.04 and OpenWrt. This happens with PHP, but I don't
think it's that relevant to the PHP wrapper (but who knows). This is part
of a complex system, so it's hard to post sample code.

Here's what I have:

PHP curl multi stuff, doing a fetch to a single device to fetch its status -
simple REST/json stuff.

Another PHP select loop in the program, for completely unrelated, non-HTTP
stuff.

If the fetch is done in the foreground, then it works fine.
If the fetch is done in the background, and I disable the other select, then it
works fine.
If I strace the process (with background fetch), then it works fine. In
particular, the strace situation makes it hard to debug.

In a previous version of the code (probably using older version of curl without
my debug in it), the background fetch would *always* succeed the first time,
then almost always fail the second, then probably 1 time out of 10 work.
In the current version, it often fails the first time too.

The device in question I believe is robust - I've written curl/shell scripts
to test hundreds of fetches against it with no problem.

At the bottom of this post is an strace. You can see in it the unrelated
select, and the connect/recv/poll etc from curl (fd 8). As noted above,
this works with strace, so is what is supposed to happen.

Inside the curl code itself, I've gone through all the relevant network
code, and there's nothing obviously wrong (nor would I expect there
to be in such a mature piece of code). Also check all the errors codes,
etc (have turned on EINTR stuff). What I do know is that
in the failure case, recv() returns 0 on the first call. To the very best of
my knowledge, recv() only ever returns 0 when the other end has closed connection.

So in summary/speculation:

- strace is doing something to make it work 100%, quite possibly signals
   related.
- the other select is causing something network wise to happen on the
   curl socket.
- maybe some error condition/some network flag is not being set correctly
   in all cases for curl multi.

Let me know where I might want to look .

Many thanks. You can find me as "Chocky" on IRC.

clock_gettime(CLOCK_MONOTONIC, {77811, 290297463}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 290896305}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 291240136}) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 8
fcntl64(8, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 293165713}) = 0
connect(8, {sa_family=AF_INET, sin_port=htons(80),
sin_addr=inet_addr("10.38.0.142")}, 16) = -1 EINPROGRESS (Operation now in progress)
clock_gettime(CLOCK_MONOTONIC, {77811, 294348881}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 294858906}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 295253016}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 295712206}) = 0
poll([{fd=8, events=POLLOUT|POLLWRNORM}], 1, 0) = 1 ([{fd=8,
revents=POLLOUT|POLLWRNORM}])
getsockopt(8, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 297186148}) = 0
getpeername(8, {sa_family=AF_INET, sin_port=htons(80),
sin_addr=inet_addr("10.38.0.142")}, [16]) = 0
getsockname(8, {sa_family=AF_INET, sin_port=htons(53505),
sin_addr=inet_addr("10.38.0.137")}, [16]) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 298513171}) = 0
send(8, "GET /api/6520b1d95192131da4654f3"..., 163, MSG_NOSIGNAL) = 163
time(NULL) = 1364410532
send(7, "<15>Mar 27 11:55:32 php-cgi: sen"..., 44, MSG_NOSIGNAL) = 44
clock_gettime(CLOCK_MONOTONIC, {77811, 301578934}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 301864953}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 302254040}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 302536707}) = 0
poll([{fd=8, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1 ([{fd=8,
revents=POLLIN|POLLRDNORM}])
recv(8, "HTTP/1.1 200 OK\r\nCache-Control: "..., 16384, 0) = 550
time(NULL) = 1364410532
send(7, "<15>Mar 27 11:55:32 php-cgi: rec"..., 43, MSG_NOSIGNAL) = 43
clock_gettime(CLOCK_MONOTONIC, {77811, 305843538}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 306326478}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 306630375}) = 0
clock_gettime(CLOCK_MONOTONIC, {77811, 307029799}) = 0
select(7, [4 5 6], [], [], {1, 0}) = 1 (in [4], left {0, 41149})
accept(4, {sa_family=AF_INET, sin_port=htons(40381),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 9
gettimeofday({1364410533, 27621}, NULL) = 0
recv(9, "a:2:{s:3:\"GET\";a:1:{s:3:\"cmd\";s:"..., 10000, 0) = 101
gettimeofday({1364410533, 29000}, NULL) = 0
gettimeofday({1364410533, 29962}, NULL) = 0
select(6, [5], [], [], {0, 0}) = 0 (Timeout)
write(9, "{\"ResponseCode\":0,\"ResponseVersi"..., 134) = 134
close(9) = 0
select(7, [4 5 6], [], [], {1, 0}) = 0 (Timeout)
gettimeofday({1364410534, 38082}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {77813, 279112971}) = 0
poll([{fd=8, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1 ([{fd=8,
revents=POLLIN|POLLRDNORM}])
recv(8, "}, \"type\": \"Extended color light"..., 16384, 0) = 217

-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
Received on 2013-03-27