curl closes socket in the connection cache upon reuse if CURLOPT_CONNECT_ONLY & CURL_MAXCONNECTS is set to 1

[anonymousbug94]

Changes in curl 7.64.1 close cause curl to close the socket in the connection cache upon reuse if CURLOPT_CONNECT_ONLY and CURLOPT_MAXCONNECTS are both set to 1 - this makes using curl_send and curl_recv impossible because curl reports "Failed to get recent socket"

I did this

1. create an easy handle
2. Set options to CURLOPT_URL ("http://www.example.com"), CURLOPT_VERBOSE (1L), CURLOPT_NOPROGRESS (1L), CURLOPT_CONNECT_ONLY (1L), and CURLOPT_MAXCONNECTS (1L)
3. Execute the following
   a. call curl_easy_perform - watch it succeed.
   b. use curl_send to send the following "GET / HTTP/1.1\r\nHost: www.example.com\r\n"
   c. use curl_recv to recv the response
4. repeat step 3. curl informs you that the "connection cache is full, closing the oldest one", curl_easy_perform will succeed, but curl_send will fail with error 1 unsupported protocol

I expected the following

The handle can be reused for both send and recv and the socket doesn't get closed.

curl/libcurl version

7.64.1.
tested on 7.60, 7.63, 7.64.0 - all work, the problem seems isolated to 7.64.1

[curl -V output]

operating system

Linux and others

demonstration

this sample demonstrates the problem

#include <stdio.h>
#include <string.h>
#include <curl.h>

int SendRecv(CURL* curl, char* buffer, size_t buffersize)
{
    size_t nsize = 0, size = 0;
    char getMsg[] = "GET / HTTP/1.1\r\nHost: www.example.com\r\n\r\n";

    CURLcode res = curl_easy_send(curl, getMsg, strlen(getMsg), &size);
    printf("send curl code:%s (%d),\n%s\n", curl_easy_strerror(res), res, getMsg);
    memset(buffer, 0, buffersize);

    do
    {
      res = curl_easy_recv(curl, buffer + nsize, buffersize - nsize, &size);
      nsize += size;
    } while (buffersize - nsize > 0 && res == CURLE_AGAIN);

    buffer[size < 300 ? size : 300] = 0; // just show some of it for illustrative purposes
    printf("recv curl code:%s (%d)\n%s\n", curl_easy_strerror(res), res, buffer);
}

int main(int argc, char* argv[])
{
    const char* url = "http://www.example.com";
    CURL* curl = NULL;
    CURLcode res;
    char buffer[4096];

    res = curl_global_init(CURL_GLOBAL_DEFAULT);
    if( res != CURLE_OK )
    {
        goto bail;
    }

    curl = curl_easy_init();
    if (curl == NULL)
    {
      goto bail;
    };

    curl_easy_setopt(curl, CURLOPT_URL, url);
    curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
    curl_easy_setopt(curl, CURLOPT_NOPROGRESS, 0L);
    curl_easy_setopt(curl, CURLOPT_CONNECT_ONLY, 1L);
    curl_easy_setopt(curl, CURLOPT_MAXCONNECTS, 1L);

    res = curl_easy_perform(curl);
    if (res != CURLE_OK)
    {
      printf("\n curl_easy_perform failed! %s (%d).\n", curl_easy_strerror(res), res);
      goto bail;
    }
    printf("\n curl_easy_perform succeeded!\n");
    SendRecv(curl, buffer, sizeof(buffer));

    res = curl_easy_perform(curl);
    if (res != CURLE_OK)
    {
      printf("\n curl_easy_perform failed! %s (%d).\n", curl_easy_strerror(res), res);
      goto bail;
    }
    printf("\n curl_easy_perform succeeded!\n");
    SendRecv(curl, buffer, sizeof(buffer));

bail:
    curl_easy_cleanup(curl);
    curl_global_cleanup();
    return 0;
}

problem

I tracked the problem to the the below code

diff --git a/lib/conncache.c b/lib/conncache.c
index 39302ba7b..d61b3bcf7 100644
--- a/lib/conncache.c
+++ b/lib/conncache.c
@@ -477,7 +477,7 @@ Curl_conncache_extract_bundle(struct Curl_easy *data,
   while(curr) {
     conn = curr->ptr;

-    if(!CONN_INUSE(conn) && !conn->data) {
+    if(!CONN_INUSE(conn)/* && !conn->data*/) {
       /* Set higher score for the age passed since the connection was used */
       score = Curl_timediff(now, conn->now);

@@ -535,7 +535,7 @@ Curl_conncache_extract_oldest(struct Curl_easy *data)
     while(curr) {
       conn = curr->ptr;

-      if(!CONN_INUSE(conn) && !conn->data) {
+      if(!CONN_INUSE(conn) /* && !conn->data */) { 
         /* Set higher score for the age passed since the connection was used */
         score = Curl_timediff(now, conn->now);

[bagder]

What do you think the second call to curl_easy_perform() should do with the first connection that you had created and that is still open? You've asked for curl to not use more than one connection...

[jay]

Probably e06b8bd nevermind, that came after 7.64.1, but maybe that is the solution?

[bagder]

@jay my initial thought was also that it was related to that change, but I ran the example code with current master. That's what triggered my question to @anonymousbug94 as I frankly don't understand how it is supposed to be allowed create (and keep) the second connection there!

[anonymousbug94]

@bagder it looks like a regression to me; it looks like it successfully reuses the connection in the cache under 7.63.0

> $ cat make.sh
> gcc -I /home/briala06/curl/include/curl/ maxconnectclose.c $1 -lz -lcrypto -lpthread -lssl
> $ ./make.sh ./libcurl-7_63_0.a
> $ ./a.out
>   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
>                                  Dload  Upload   Total   Spent    Left  Speed
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 93.184.216.34...
> * TCP_NODELAY set
> * Connected to www.example.com (93.184.216.34) port 80 (#0)
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
> * Connection #0 to host www.example.com left intact
> 
>  curl_easy_perform succeeded!
> send curl code:No error (0),
> GET / HTTP/1.1
> Host: www.example.com
> 
> 
> recv curl code:No error (0)
> HTTP/1.1 200 OK
> Cache-Control: max-age=604800
> Content-Type: text/html; charset=UTF-8
> Date: Mon, 03 Jun 2019 21:20:27 GMT
> Etag: "1541025663+ident"
> Expires: Mon, 10 Jun 2019 21:20:27 GMT
> Last-Modified: Fri, 09 Aug 2013 23:54:35 GMT
> Server: ECS (sec/976A)
> Vary: Accept-Encoding
> X-Cache: HIT
> Co
> * Found bundle for host www.example.com: 0x562380ae9ab0 [serially]
> * **Re-using existing connection! (#0) with host www.example.com**
> * Connected to www.example.com (93.184.216.34) port 80 (#0)
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
> * Connection #0 to host www.example.com left intact
> 
>  curl_easy_perform succeeded!
> send curl code:No error (0),
> GET / HTTP/1.1
> Host: www.example.com
> 
> 
> recv curl code:No error (0)
> HTTP/1.1 200 OK
> Accept-Ranges: bytes
> Cache-Control: max-age=604800
> Content-Type: text/html; charset=UTF-8
> Date: Mon, 03 Jun 2019 21:20:27 GMT
> Etag: "1541025663"
> Expires: Mon, 10 Jun 2019 21:20:27 GMT
> Last-Modified: Fri, 09 Aug 2013 23:54:35 GMT
> Server: ECS (sec/97A6)
> Vary: Accept-Encoding

whereas with 7.64.1 we get the following results

> $ ./make.sh ./libcurl-7_64_1.a
> $ ./a.out
>   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
>                                  Dload  Upload   Total   Spent    Left  Speed
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 93.184.216.34...
> * TCP_NODELAY set
> * Connected to www.example.com (93.184.216.34) port 80 (#0)
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
> * Connection #0 to host www.example.com left intact
> 
>  curl_easy_perform succeeded!
> send curl code:No error (0),
> GET / HTTP/1.1
> Host: www.example.com
> 
> 
> recv curl code:No error (0)
> HTTP/1.1 200 OK
> Accept-Ranges: bytes
> Cache-Control: max-age=604800
> Content-Type: text/html; charset=UTF-8
> Date: Mon, 03 Jun 2019 21:23:44 GMT
> Etag: "1541025663"
> Expires: Mon, 10 Jun 2019 21:23:44 GMT
> Last-Modified: Fri, 09 Aug 2013 23:54:35 GMT
> Server: ECS (sec/96DC)
> Vary: Accept-Encoding
> 
> * Hostname www.example.com was found in DNS cache
> *   Trying 93.184.216.34...
> * TCP_NODELAY set
> * Connected to www.example.com (93.184.216.34) port 80 (#1)
>   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
> * **Connection cache is full, closing the oldest one.**
> * Closing connection 1
> 
>  curl_easy_perform succeeded!
> * Failed to get recent socket
> send curl code:Unsupported protocol (1),
> GET / HTTP/1.1
> Host: www.example.com
> 
> 
> * Failed to get recent socket
> recv curl code:Unsupported protocol (1)
> 
> * Closing connection 0
> $

[bagder]

it looks like a regression to me

That didn't answer my question though: what did you expect it to do, not what libcurl did previously.

libcurl cannot ever safely reuse a connection that has been done with CONNECT_ONLY so even if it once did that, that was a mistake that could cause it to end up in bad places.

So, since it can't reuse the connection it wants to open a new one since the old one isn't closed yet... and... yeah, then it can't store the second one in the cache and thus it can't use it for CONNECT_ONLY.

[bagder]

The question is perhaps why libcurl would keep the first one alive when the second curl_easy_perform() is called since it can't be reused again... The correct behavior here might be to force-close the connection at that point and then it'll have space for the new one.

[anonymousbug94]

I think your solution sounds reasonable. Thank you for looking at it so quickly!

[bagder]

Thinking more on this use case, I'm not sure that's the right behavior either. The use of CONNECT_ONLY implies that the user intends to do something special with the connection/socket and libcurl thus marks it as such. Special. Such a special connection cannot be reused as already mentioned, but it is also not exactly sure that libcurl should just close the connection if you call curl_easy_perform() again on the same handle.

Given your example and issue here, I take it you expected it to do a connection reuse and just start over?

I would urge you to do a curl_easy_cleanup() on the handle to first close the previous connection and socket correctly, then do a new curl_easy_init() + curl_easy_perform(). That would be much more explicit behavior and not rely on curl second-guessing your desires.

[anonymousbug94]

Hello,

We are curious about the error code that curl returns. Namely is the below error message appropriate for this (mis) use-case?
Thanks

Failed to get recent socket
and error code
curl code:1
^

[bagder]

We are curious about the error code that curl returns

When and from which function?

[anonymousbug94]

The second curl_easy_perform

[bagder]

That's wrong, isn't it?

I read the code and the error message Failed to get recent socket is only returned from easy_connection here:

curl/lib/easy.c

Line 1071 in 8b987cc

failf(data, "Failed to get recent socket");

... and that function is only called from curl_easy_recv and curl_easy_send.

So yeah, you call one of those functions and libcurl tells you that it can't fetch the most recent socket. And it can't do that, because you still have the first one in use and told curl that it can't store more than one in its connection cache.

This doesn't seem to be a curl bug...