curl-library
Serious sporadic bug in libcurl 7.10
Date: Fri, 10 Jun 2005 00:39:02 -0400
I'm experiencing serious, strange and sporadic data corruption using
PUT requests from curl-devel-7.10.4-1 and curl-devel-7.10.6-6.rhel3
The application is dead-simple: a small textbook C libcurl program
(source attached) reads filenames from stdin, and PUTs each file to
the URL given on the command line. This is run from another dispatch
program that creates a unix fifo pipe and spawns the C program when
there are new files for the subscriber; the C program lingers for
5 minutes in case there are more, then exits.
When bandwidth is not an issue, it works perfectly, never any
transmission errors.
Over DSL-grade connections we see HTTP headers /inserted/ into the
body of the transmitted file:
<team>
<team-metadata xmlns:fs="java.io.File" team-key="l.mlb.com-t.7" alignment="away">
<name first="Cleveland" last="Indians" />
</team-metadata>
<team-stats score="0" event-outcome="undecided" />
</team>
<team>
<team-metadata xPUT / HTTP/1.1
Host: 99.99.99.99:8083
Pragma: no-cache
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*
Content-Length: 30434
mlns:fs="java.io.File" team-key="l.mlb.com-t.5" alignment="home">
<name first="Toronto" last="Blue Jays" />
</team-metadata>
<team-stats score="0" event-outcome="undecided" />
</team>
And here's what is really most disturbing: Those are not the headers
for the /current/ PUT transaction, they are the headers for the _next_
transaction! Inserted into the midst of the current document stream.
How could this happen? Data corrpution from the FUTURE?? Cool.
The C program isn't multi-threaded, there's only one instance per
target host, and it's totally /linear/: read a filename, PUT that
file, repeat.
Here's a debug trace of the above transaction:
2005-06-09 18:08:08 DEBUG: PUT baseball/l.mlb.com/schedules/xt.2951321-cle-sked.xml
2005-06-09 18:08:08 DEBUG: Sending 169537 bytes
2005-06-09 18:08:08 DEBUG: 65536 bytes read
* Re-using existing connection! (#0)
* Connected to target-host.net (99.99.99.99) port 8083
> PUT / HTTP/1.1^M
Host: 99.99.99.99:8083^M
Pragma: no-cache^M
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*^M
Content-Length: 169537^M
^M
2005-06-09 18:08:08 DEBUG: 16384 bytes sent
2005-06-09 18:08:08 DEBUG: 16384 bytes sent
2005-06-09 18:08:08 DEBUG: 16384 bytes sent
2005-06-09 18:08:08 DEBUG: 16384 bytes sent
2005-06-09 18:08:08 DEBUG: 65536 more bytes read
2005-06-09 18:08:08 DEBUG: 16384 bytes sent
2005-06-09 18:08:09 DEBUG: 16384 bytes sent
2005-06-09 18:08:09 DEBUG: 16384 bytes sent
2005-06-09 18:08:09 DEBUG: 16384 bytes sent
2005-06-09 18:08:09 DEBUG: 38465 more bytes read
2005-06-09 18:08:09 DEBUG: 16384 bytes sent
* Operation timed out with 0 out of -1 bytes received
* Connection #0 left intact
2005-06-09 18:08:09 SENT: baseball/l.mlb.com/schedules/xt.2951321-cle-sked.xml
The Ruby WebBrick records nothing special, just the expected content
length that just happens to have the future header jazz injected into
the stream.
The headers for the immediately following message, as recorded by the
libcurl application:
* Re-using existing connection! (#0)
* Connected to target-host.net (99.99.99.99) port 8083
> PUT / HTTP/1.1^M
Host: 99.99.99.99:8083^M
Pragma: no-cache^M
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*^M
Content-Length: 30434^M
^M
2005-06-09 18:08:23 DEBUG: 16384 bytes sent
2005-06-09 18:08:23 DEBUG: 14050 bytes sent
2005-06-09 18:08:23 DEBUG: transfer complete
* Connection #0 left intact
those are the headers allright.
We have verified the bug using both a Perl HTTP::Daemon and a Ruby
WebBrick test program. On a windows receiver, the error is frequent,
about 20% of the documents are corrupted and there is no pattern to
the particular doc type, it's size or the time of day. On a Linux
receiver on 500Mb/s DSL the error rate is much less, one in 500,
but it is still not zero.
It's also not happening on a clean 16k boundary; the above error
happened 141744 bytes into the XML file.
Some notes on the attached C file (I hope the list allows attachments)
1) I moved the following code from outside the read/PUT loop to be
inline each cycle just before we send the PUT, just in case these
functions have side effects that clear their buffers. I don't know
I'm grasping at straws ;)
curl_easy_setopt(curl,CURLOPT_URL, target_url);
curl_easy_setopt(curl, CURLOPT_UPLOAD, TRUE) ;
2) The docs say that easy_init and easy_cleanup are to be done at
the beginning and end of a "session" -- I take that to mean a
flurry of PUTs is a "session"
is this too generous? Should I be doing the init/cleanup for
each individual PUT? Shorten my wait-time because the remote
receiver may be timing out before I do and confusing my next
doc (but then, why do the headers get injected and not simply
switch from Doc-A to Doc-B?)
the general pattern of PUTs tends to be clumps of update XML docs,
as many as several dozen within a few seconds, then a pause of up
to a few minutes, or during off-hours, pauses of hours. The
program keeps alive for 5 minutes awaiting new content orders, then
uses SIGALRM to close the session and exit.
3) There is a suspicious 1-second timeout -- do not be alarmed;
another bug we were wrestling with saw the remote Windows clients
pausing up to 60 seconds after receiving each PUT request so to
"just make it work" the chief engineer ordered a "hurl and forget"
policy; this bug with the injected HTTP headers was happening even
when the timeout was 60 seconds (but maybe that is still a
significant clue?)
This bug has us stymied, it makes no sense. While sending a document
through a PUT request, we see log messages for each 16k block filled
by the read callback, and we see the transaction close either by an
acknowledge ment or because of the timeout, and we see all that happen
_before_ the log shows the handshake for the subsequent transactions,
So how can HTTP headers from the _next_ PUT get into the middle of one
of those 16k blocks?
Any hints, tips, theories or wild guesses are eagerly welcome.
-- Gary Lawrence Murphy <garym_at_teledyn.com> ============================== ====================== The present moment is a powerful goddess (Goethe)
- application/octet-stream attachment: Simple PUT send-process libcurl program