10

I am using libcurl to send an API command to a local service (i.e. on 127.0.0.1).

The program is intended to replace a shell script (that uses the curl program.)

Everything is working, except that there is a 1-second delay somewhere, i.e 1 second elapses from the time I call curl_easy_perform() to when my read callback function is first called.

The C program is using these options (error checking & callback code omitted):

curl_easy_setopt(curl, CURLOPT_URL, "http://127.0.0.1:12345/x");
curl_easy_setopt(curl, CURLOPT_UPLOAD, 1);
curl_easy_setopt(curl, CURLOPT_INFILESIZE, (long)getLengthOfCommandObject());
curl_easy_setopt(curl, CURLOPT_READFUNCTION, &myReadFunction);
curl_easy_setopt(curl, CURLOPT_WRITEFUNCTION, &myWriteFunction);

But if I run curl from the shell like this: 

$ curl --data-binary '<command>' http://127.0.0.1:12345/x

it sends the request immediately, without suffering from the 1-second delay.

What might be causing the delay, and is there an option I can set to prevent it?

Edit The server is based on mongoose

finnw
  • 47,861
  • 24
  • 143
  • 221
  • 1
    Did you try executing your binary with _strace_ ? it could show any delay at program execution. Man page of strace has many time related options. – VoidPointer Jun 29 '13 at 18:31
  • @VoidPointer, strace did not reveal anything relevant, but I found the cause. See my answer. – finnw Jun 30 '13 at 13:48
  • Even the authors of libcurl [think this behaviour of libcurl is a mistake](https://curl.haxx.se/mail/lib-2017-07/0013.html). – Raedwald Oct 30 '18 at 16:01

3 Answers3

19

The reason for the delay was:

A solution on the client side is to disable the Expect header like so:

headers = curl_slist_append(NULL, "Expect:");
curl_easy_setopt(curl, CURLOPT_HTTPHEADER, headers);
// ...
result = curl_easy_perform(curl);
curl_slist_free_all(headers);

Equivalent fix for PHP client and related PHP question

Community
  • 1
  • 1
finnw
  • 47,861
  • 24
  • 143
  • 221
  • Just out of interest, how do you check that an `Expect: 100-continue` header is being sent by libcurl? I'm having similar delays, maybe this is the problem...I'm just not sure how to check if this is being sent within my request header. Thank you – p.luck Nov 24 '21 at 15:48
0

This answer is not an Answer, but shows where the problem is happening in curl. I had the same problem with libcurl versus Civet which is based on mongoose.

I had the same problem and did run strace to attempt to debug. This is the output from strace (with a timestamp in seconds on each line). The issue is that there is a sequence of poll( ...events=POLLIN...) calls that block for a total of 1000 milliseconds (1+98+1+900) after the header is sent, before the body is sent. You can see the gap in timestamps from 17.935024 to 18.931842.

17.934881 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 5
17.934898 fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR)
17.934916 fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
17.934934 connect(5, {sa_family=AF_INET, sin_port=htons(37034), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress)
17.934952 poll([{fd=5, events=POLLOUT|POLLWRNORM}], 1, 0) = 1 ([{fd=5, revents=POLLOUT|POLLWRNORM}])
17.934970 getsockopt(5, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
17.934988 getpeername(5, {sa_family=AF_INET, sin_port=htons(37034), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
17.935006 getsockname(5, {sa_family=AF_INET, sin_port=htons(46830), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
17.935024 sendto(5, "POST /foo/1/bar HTTP/"..., 168, MSG_NOSIGNAL, NULL, 0) = 168
17.935042  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
17.935060  poll([{fd=5, events=POLLIN}], 1, 1)     = 0 (Timeout)
17.935078  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
18.029421  poll([{fd=5, events=POLLIN}], 1, 98)    = 0 (Timeout)
18.029518  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
18.030576  poll([{fd=5, events=POLLIN}], 1, 1)     = 0 (Timeout)
18.030681  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
18.931571  poll([{fd=5, events=POLLIN}], 1, 900)   = 0 (Timeout)
18.931642  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
18.931698  poll([{fd=5, events=POLLIN}, {fd=5, events=POLLOUT}], 2, 1000) = 1 ([{fd=5, revents=POLLOUT}])
18.931726  poll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}, {fd=5, events=POLLOUT|POLLWRNORM}], 2, 0) = 1 ([{fd=5, revents=POLLOUT|POLLWRNORM}])
18.931842 sendto(5, "{\"foo\":[{\"bar\":\"A\",\"e"..., 1642, MSG_NOSIGNAL, NULL, 0) = 1642

I had the same problem with both the command-line curl as well as with curl_easy_perform, but I did not have the problem using a different REST client such as Postman.

Mark Lakata
  • 19,989
  • 5
  • 106
  • 123
0

Thanks to @finnw's answer and the discussion here (https://groups.google.com/g/mongoose-users/c/92fD1Elk5m4?pli=1), I was able to patch CivetWeb to support the 100-continue feature with the following (see #ifdef DEXPECT_100_CONTINUE_FIX).

void
CivetServer::getPostData(struct mg_connection *conn, std::string& dst)
{

    struct mg_request_info *ri = mg_get_request_info(conn);
    assert(ri != NULL);
    CivetServer *me = (CivetServer*) (ri->user_data);
    assert(me != NULL);
    mg_lock_context(me->context);
    CivetConnection &conobj = me->connections[conn];
    mg_lock_connection(conn);
    mg_unlock_context(me->context);

#ifdef EXPECT_100_CONTINUE_FIX
    const char * expect_str = mg_get_header(conn, "Expect");
    if (expect_str)
    {
        printf("CivetServer::getParam, Expect:%s\n", expect_str);
        if (strcmp(expect_str,"100-continue") == 0)
        {
            mg_printf(conn, "%s", "HTTP/1.1 100 Continue\r\n\r\n");
        }
    }
    else
    {
        printf("CivetServer::getParam, Expect: blank\n");
    }
#endif
Mark Lakata
  • 19,989
  • 5
  • 106
  • 123