libcurl fails when buffering trailing headers when there's a paused response body write

[stephentoub]

Using a build from recent libcurl sources (7.53.0-DEV) on Ubuntu 16.10, it appears libcurl has trouble with the following situation:

• Chunked response with trailer header, and
• A write callback that pauses such that there's body data in the buffer when libcurl tries to write the header

For example, if the HTTP response is:

HTTP/1.1 200 OK\r\n
Transfer-Encoding: chunked\r\n
Trailer: MyCoolTrailerHeader\r\n
\r\n
4\r\n
data\r\n
0\r\n
MyCoolTrailerHeader: amazingtrailer\r\n
\r\n

and the write callback returns CURL_WRITEFUNC_PAUSE when handed the body data, libcurl ends up failing here:

curl/lib/transfer.c

Lines 638 to 640 in 66de563

	if(CHUNKE_WRITE_ERROR == res) {
	failf(data, "Failed writing data");
	return CURLE_WRITE_ERROR;

It looks like this is because it's processing a buffer that contains both the chunk data and the trailing header, so after issuing the pausewrite and getting a CURLE_OK from that, it continues to process the remainder of the buffer, and ends up here while processing the trailer:

curl/lib/http_chunks.c

Line 275 in 66de563

result = Curl_client_write(conn, CLIENTWRITE_HEADER,

That then ends up in Curl_client_chop_write here:

curl/lib/sendf.c

Lines 517 to 522 in 66de563

	if(data->req.keepon & KEEP_RECV_PAUSE) {
	size_t newlen;
	char *newptr;
	if(type != data->state.tempwritetype)
	/* major internal confusion */
	return CURLE_RECV_ERROR;

and since the type of the data buffered is for the body but it's now trying to buffer header data, this fails as "major internal confusion", returns CURLE_RECV_ERROR, which then gets translated up the call stack to a CHUNKE_WRITE_ERROR and then to the CURLE_WRITE_ERROR, and the request fails.

[bagder]

Have you tried to make any sort of reproducible example for this? It is a rather complicated scenario what you describe, so getting code to debug would help a lot! And ideally to add to the test suite.

[stephentoub]

Sure, here you go:

// file: curlrepro.c

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <netinet/ip.h>
#include <curl/curl.h>
#include <pthread.h>

static size_t write_callback(void *ptr, size_t size, size_t nmemb, void *userp)
{
    return size * nmemb;
    //return CURL_WRITEFUNC_PAUSE;
}

void* acceptConnection(void* listenfdPtr)
{
    struct sockaddr_in clientaddr;
    int clientaddrlen = sizeof(clientaddr);
    int fd = accept(*(int*)listenfdPtr, (struct sockaddr*)&clientaddr, &clientaddrlen);
    if (fd < 0) { perror("accept failed"); exit(-1); }

    char* response =
        "HTTP/1.1 200 OK\r\n"
        "Transfer-Encoding: chunked\r\n"
        "Trailer: MyCoolTrailerHeader\r\n"
        "\r\n"
        "4\r\n"
        "data\r\n"
        "0\r\n"
        "MyCoolTrailerHeader: amazingtrailer\r\n"
        "\r\n";
    int r = write(fd, response, strlen(response));
    if (r < 0) { perror("write failed"); exit(-1); }

    shutdown(fd, SHUT_WR);
    return NULL;
}

int main(void)
{
    int listenfd = socket(PF_INET, SOCK_STREAM, 0);
    if (listenfd < 0) { perror("socket failed"); return -1; }

    struct sockaddr_in addr = {};
    addr.sin_family = AF_INET;
    addr.sin_addr.s_addr = INADDR_ANY;
    addr.sin_port = 0;
    int addrlen = sizeof(addr);

    if (bind(listenfd, (struct sockaddr*)&addr, addrlen) < 0) { perror("bind failed"); return -1; }
    if (getsockname(listenfd, (struct sockaddr*)&addr, (socklen_t*)&addrlen) < 0) { perror("getsockname failed"); return -1; }
    if (listen(listenfd, 100) < 0) { perror("listen failed"); return -1; }

    pthread_t acceptThread;
    int err = pthread_create(&acceptThread, NULL, acceptConnection, &listenfd);
    if (err != 0) { printf("pthread_create failed: %d\n", err); return -1; }

    char url[100];
    sprintf(url, "http://localhost:%d/", ntohs(addr.sin_port));

    curl_global_init(CURL_GLOBAL_ALL);
    CURL *curl = curl_easy_init();
    curl_easy_setopt(curl, CURLOPT_URL, url);
    curl_easy_setopt(curl, CURLOPT_WRITEFUNCTION, write_callback);
    curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
    CURLcode res = curl_easy_perform(curl);
    printf("curl_easy_perform returned: %s\n", curl_easy_strerror(res));
    curl_easy_cleanup(curl);
    curl_global_cleanup();

    return 0;
}

I compile it with:

gcc -o curlrepro curlrepro.c -lcurl -lpthread

The above runs successfully:

stoub@SToubUbuntu1610:~$ ./curlrepro
./curlrepro: /usr/local/lib/libcurl.so.4: no version information available (required by ./curlrepro)
Url: http://localhost:36745/
* STATE: INIT => CONNECT handle 0x560241806058; line 1415 (connection #-5000)
* Added connection 0. The cache now contains 1 members
*   Trying 127.0.0.1...
* TCP_NODELAY set
* STATE: CONNECT => WAITCONNECT handle 0x560241806058; line 1468 (connection #0)
* Connected to localhost (127.0.0.1) port 36745 (#0)
* STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x560241806058; line 1585 (connection #0)
* Marked for [keep alive]: HTTP default
* STATE: SENDPROTOCONNECT => DO handle 0x560241806058; line 1603 (connection #0)
> GET / HTTP/1.1
Host: localhost:36745
Accept: */*

* STATE: DO => DO_DONE handle 0x560241806058; line 1682 (connection #0)
* STATE: DO_DONE => WAITPERFORM handle 0x560241806058; line 1809 (connection #0)
* STATE: WAITPERFORM => PERFORM handle 0x560241806058; line 1819 (connection #0)
* HTTP 1.1 or later with persistent connection, pipelining supported
< HTTP/1.1 200 OK
< Transfer-Encoding: chunked
< Trailer: MyCoolTrailerHeader
<
* STATE: PERFORM => DONE handle 0x560241806058; line 1983 (connection #0)
* multi_done
* Connection #0 to host localhost left intact
* Expire cleared
curl_easy_perform returned: No error
stoub@SToubUbuntu1610:~$

If I then change the write_callback implementation to switch the line that's commented out (commenting the one that returns the correct size and uncommenting the one that returns CURL_WRITEFUNC_PAUSE, I get:

stoub@SToubUbuntu1610:~$ ./curlrepro
./curlrepro: /usr/local/lib/libcurl.so.4: no version information available (required by ./curlrepro)
Url: http://localhost:55903/
* STATE: INIT => CONNECT handle 0x55b1a6226058; line 1415 (connection #-5000)
* Added connection 0. The cache now contains 1 members
*   Trying 127.0.0.1...
* TCP_NODELAY set
* STATE: CONNECT => WAITCONNECT handle 0x55b1a6226058; line 1468 (connection #0)
* Connected to localhost (127.0.0.1) port 55903 (#0)
* STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x55b1a6226058; line 1585 (connection #0)
* Marked for [keep alive]: HTTP default
* STATE: SENDPROTOCONNECT => DO handle 0x55b1a6226058; line 1603 (connection #0)
> GET / HTTP/1.1
Host: localhost:55903
Accept: */*

* STATE: DO => DO_DONE handle 0x55b1a6226058; line 1682 (connection #0)
* STATE: DO_DONE => WAITPERFORM handle 0x55b1a6226058; line 1809 (connection #0)
* STATE: WAITPERFORM => PERFORM handle 0x55b1a6226058; line 1819 (connection #0)
* HTTP 1.1 or later with persistent connection, pipelining supported
< HTTP/1.1 200 OK
< Transfer-Encoding: chunked
< Trailer: MyCoolTrailerHeader
<
* Pausing with 4 bytes in buffer for type 01
* Failed writing data
* Marked for [closure]: Transfer returned error
* multi_done
* Closing connection 0
* The cache now contains 0 members
* Expire cleared
curl_easy_perform returned: Failed writing received data to disk/application
stoub@SToubUbuntu1610:~$

noting in particular the pause followed by the failure:

* Pausing with 4 bytes in buffer for type 01
* Failed writing data

If I then go back to the repro and just comment out the line:

"MyCoolTrailerHeader: amazingtrailer\r\n"

things go back to working successfully, though obviously hanging as expected since my write callback paused everything:

stoub@SToubUbuntu1610:~$ ./curlrepro
./curlrepro: /usr/local/lib/libcurl.so.4: no version information available (required by ./curlrepro)
Url: http://localhost:37345/
* STATE: INIT => CONNECT handle 0x559206e13058; line 1415 (connection #-5000)
* Added connection 0. The cache now contains 1 members
*   Trying 127.0.0.1...
* TCP_NODELAY set
* STATE: CONNECT => WAITCONNECT handle 0x559206e13058; line 1468 (connection #0)
* Connected to localhost (127.0.0.1) port 37345 (#0)
* STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x559206e13058; line 1585 (connection #0)
* Marked for [keep alive]: HTTP default
* STATE: SENDPROTOCONNECT => DO handle 0x559206e13058; line 1603 (connection #0)
> GET / HTTP/1.1
Host: localhost:37345
Accept: */*

* STATE: DO => DO_DONE handle 0x559206e13058; line 1682 (connection #0)
* STATE: DO_DONE => WAITPERFORM handle 0x559206e13058; line 1809 (connection #0)
* STATE: WAITPERFORM => PERFORM handle 0x559206e13058; line 1819 (connection #0)
* HTTP 1.1 or later with persistent connection, pipelining supported
< HTTP/1.1 200 OK
< Transfer-Encoding: chunked
< Trailer: MyCoolTrailerHeader
<
* Pausing with 4 bytes in buffer for type 01

[bagder]

Perfect, thanks a lot for the code. I can reproduce this issue and I see the problem clearly. I'll work on a fix. I've also managed to convert your code into a test case for the test suite for inclusion once I get somewhere on this.

[bagder]

@stephentoub, it would be great if you can try that PR #1357 on your case and see if it works as good as it does for my test case!

[stephentoub]

@bagder, thanks for the fast turnaround! I pulled down the PR, tried it out, and it does address the problem I was hitting.

[bagder]

Lovely, thanks for confirming @stephentoub. I'll get this landed once everything looks fine.