Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CURLINFO_PRIMARY_IP, CURLINFO_PRIMARY_PORT empty with CURLOPT_TCP_FASTOPEN #4296

Closed
patrickkh7788 opened this issue Sep 5, 2019 · 10 comments
Closed

Comments

@patrickkh7788
Copy link

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

curl 7.65.3 with woflSSL v4.1.0, cares 1_15_0, test base on this code example: https://curl.haxx.se/libcurl/c/multi-uv.html

test from os: macOS, linux, android. all has same issue.

CURLINFO_PRIMARY_IP, CURLINFO_PRIMARY_PORT return null and 0 at CURLMSG_DONE callback function. (test before curl_multi_assign(null), curl_multi_remove_handle )

CURL_POLL_REMOVE is called before CURLMSG_DONE, I guess this could be the problem.

I use getpeername to get the socket peer IP, on step CURL_POLL_REMOVE I can get the correct peer IP.

On step CURL_POLL_IN, if socketp is null, peer IP also is null. (Even I remove uv_close from CURL_POLL_REMOVE , so socket get reused without call uv_close)

I also try delay curl_multi_remove_handle until before curl_easy_cleanup get called, this will allow CURLINFO_ACTIVESOCKET return a valid socket fd (without delay curl_multi_remove_handle, CURLINFO_ACTIVESOCKET return -1 when easy finished ).

According to https://ec.haxx.se/libcurl-connectionreuse.html:

When you are using the multi API, the connection pool is instead kept associated with the multi handle. This allows you to cleanup and re-create easy handles freely without risking losing the connection pool, and it allows the connection used by one easy handle to get reused by a separate one in a later transfer.

In the test code, connection not reused all the time.

The TLS session cache also get destroyed when multi handle perform a new host request.

For TLS version < 1.3, If the socket peer IP remain same, and domain remain same, TLS session cache still not work. I guess because TLSv1.2 no 0-rtt handshake, and connection is not reused(the TLSv1.2 session cache should speed up the connection time cost, but the test code show the same time cost ).

@bagder bagder added the libcurl API label Sep 5, 2019
@bagder

This comment has been minimized.

Copy link
Member

@bagder bagder commented Sep 5, 2019

Can you provide a small stand-alone example showing the problem?

@patrickkh7788

This comment has been minimized.

Copy link
Author

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

Here is the test example, to build: gcc tests.c -luv -lcurl -lssl -lng2 -lcares -lz

#include <stdio.h>
#include <stdlib.h>
#include <assert.h>
#include <uv.h>
#include <curl/curl.h>
 
uv_loop_t *loop;
CURLM *curl_handle;
uv_timer_t timeout;

char* gURL = NULL;
int gIndex = 0;

 
typedef struct curl_context_s {
  uv_poll_t poll_handle;
  curl_socket_t sockfd;
} curl_context_t;
 
static curl_context_t* create_curl_context(curl_socket_t sockfd)
{
  curl_context_t *context;
 
  context = (curl_context_t *) malloc(sizeof(*context));
 
  context->sockfd = sockfd;
 
  uv_poll_init_socket(loop, &context->poll_handle, sockfd);
  context->poll_handle.data = context;
  printf("create_curl_context(%p, fd=%d)\n", context, sockfd);
 
  return context;
}
 
static void curl_close_cb(uv_handle_t *handle)
{
  curl_context_t *context = (curl_context_t *) handle->data;
  printf("curl_close_socket: fd=%d\n", context->sockfd);
  free(context);
}
 
static void destroy_curl_context(curl_context_t* context)
{
  uv_close((uv_handle_t *) &context->poll_handle, curl_close_cb);
}
 
static void add_download(const char *url, int num)
{
  char filename[50];
  FILE *file;
  CURL *handle;

  snprintf(filename, 50, "%d.download", num);

  file = fopen(filename, "wb");
  if(!file) {
    fprintf(stderr, "Error opening %s\n", filename);
    return;
  }
 
  handle = curl_easy_init();
  curl_easy_setopt(handle, CURLOPT_WRITEDATA, file);
  curl_easy_setopt(handle, CURLOPT_PRIVATE, file);
  curl_easy_setopt(handle, CURLOPT_URL, url);

  curl_easy_setopt(handle, CURLOPT_REFERER, url);
  curl_easy_setopt(handle, CURLOPT_FOLLOWLOCATION, 1L);
  curl_easy_setopt(handle, CURLOPT_AUTOREFERER, 1L);
  curl_easy_setopt(handle, CURLOPT_HEADER, 0L);
  curl_easy_setopt(handle, CURLOPT_TIMEOUT, 9);
  curl_easy_setopt(handle, CURLOPT_DNS_SERVERS, "114.114.114.114");
  curl_easy_setopt(handle, CURLOPT_REDIR_PROTOCOLS, -1);

  curl_easy_setopt(handle, CURLOPT_SSL_VERIFYPEER, 1L);
  curl_easy_setopt(handle, CURLOPT_SSL_VERIFYHOST, 2L);
  curl_easy_setopt(handle, CURLOPT_VERBOSE, 0L);

  curl_easy_setopt(handle, CURLOPT_TCP_KEEPALIVE, 1L);
  curl_easy_setopt(handle, CURLOPT_TCP_KEEPIDLE, 30L);
  curl_easy_setopt(handle, CURLOPT_TCP_KEEPINTVL, 15L);
  curl_easy_setopt(handle, CURLOPT_TCP_FASTOPEN, 1L);

  curl_multi_add_handle(curl_handle, handle);
  fprintf(stderr, "fetch %s\n", url);
}
 
static void check_multi_info(void)
{
  char *done_url;
  CURLMsg *message;
  int pending;
  CURL *easy_handle;
  FILE *file;
 
  while((message = curl_multi_info_read(curl_handle, &pending))) {
    switch(message->msg) {
    case CURLMSG_DONE:
      /* Do not use message data after calling curl_multi_remove_handle() and
         curl_easy_cleanup(). As per curl_multi_info_read() docs:
         "WARNING: The data the returned pointer points to will not survive
         calling curl_multi_cleanup, curl_multi_remove_handle or
         curl_easy_cleanup." */ 
      easy_handle = message->easy_handle;
 
      curl_easy_getinfo(easy_handle, CURLINFO_EFFECTIVE_URL, &done_url);
      curl_easy_getinfo(easy_handle, CURLINFO_PRIVATE, &file);

      char *ip;
      curl_easy_getinfo(easy_handle, CURLINFO_PRIMARY_IP, &ip);
      long port;
      curl_easy_getinfo(easy_handle, CURLINFO_PRIMARY_PORT, &port);
      long ssltime;
	  int CURLINFO_APPCONNECT_TIME_T = 6291512 ;
      curl_easy_getinfo(easy_handle, CURLINFO_APPCONNECT_TIME_T, &ssltime);
      long time;
      int CURLINFO_TOTAL_TIME_T = 6291506;
      curl_easy_getinfo(easy_handle, CURLINFO_TOTAL_TIME_T, &time);

      printf("CURLMSG_DONE: ip:%s:%ld ssltime=%ld time=%ld \n\n", ip, port, ssltime / 1000, time/1000);
 
      curl_multi_remove_handle(curl_handle, easy_handle);
      curl_easy_cleanup(easy_handle);
      if(file) {
        fclose(file);
      }
      if( gIndex < 3 ) {
        add_download(gURL, gIndex++);
      }
      break;
 
    default:
      fprintf(stderr, "CURLMSG default\n");
      break;
    }
  }
}
 
static void curl_perform(uv_poll_t *req, int status, int events)
{
  int running_handles;
  int flags = 0;
  curl_context_t *context;
 
  if(events & UV_READABLE)
    flags |= CURL_CSELECT_IN;
  if(events & UV_WRITABLE)
    flags |= CURL_CSELECT_OUT;
 
  context = (curl_context_t *) req->data;
 
  curl_multi_socket_action(curl_handle, context->sockfd, flags,
                           &running_handles);
 
  check_multi_info();
}
 
static void on_timeout(uv_timer_t *req)
{
  int running_handles;
  curl_multi_socket_action(curl_handle, CURL_SOCKET_TIMEOUT, 0,
                           &running_handles);
  check_multi_info();
}
 
static int start_timeout(CURLM *multi, long timeout_ms, void *userp)
{
  if(timeout_ms < 0) {
    uv_timer_stop(&timeout);
  }
  else {
    if(timeout_ms == 0)
      timeout_ms = 1; /* 0 means directly call socket_action, but we'll do it
                         in a bit */ 
    uv_timer_start(&timeout, on_timeout, timeout_ms, 0);
  }
  return 0;
}
 
static int handle_socket(CURL *easy, curl_socket_t s, int action, void *userp,
                  void *socketp)
{
  curl_context_t *curl_context;
  int events = 0;
 
  switch(action) {
  case CURL_POLL_IN:
  case CURL_POLL_OUT:
  case CURL_POLL_INOUT:
    curl_context = socketp ?
      (curl_context_t *) socketp : create_curl_context(s);
 
    curl_multi_assign(curl_handle, s, (void *) curl_context);
 
    if(action != CURL_POLL_IN)
      events |= UV_WRITABLE;
    if(action != CURL_POLL_OUT)
      events |= UV_READABLE;
 
    uv_poll_start(&curl_context->poll_handle, events, curl_perform);
    break;
  case CURL_POLL_REMOVE:
    if(socketp) {
      printf("CURL_POLL_REMOVE: fd=%d\n", s);
      uv_poll_stop(&((curl_context_t*)socketp)->poll_handle);
      destroy_curl_context((curl_context_t*) socketp);
      curl_multi_assign(curl_handle, s, NULL);
    } else {
        assert(socketp);
    }
    break;
  default:
    abort();
  }
 
  return 0;
}

int main(int argc, char **argv)
{
  loop = uv_default_loop();
 
  if(argc <= 1)
    return 0;
 
  if(curl_global_init(CURL_GLOBAL_ALL)) {
    fprintf(stderr, "Could not init curl\n");
    return 1;
  }
 
  uv_timer_init(loop, &timeout);
 
  curl_handle = curl_multi_init();
  curl_multi_setopt(curl_handle, CURLMOPT_SOCKETFUNCTION, handle_socket);
  curl_multi_setopt(curl_handle, CURLMOPT_TIMERFUNCTION, start_timeout);
 
  while(argc-- > 1) {
    gURL = argv[argc];
    break;
  }

  if( !gURL ) {
        // TLSv1.2 test site
       gURL = "https://www.baidu.com";
  }
  add_download(gURL, gIndex++);
 
  uv_run(loop, UV_RUN_DEFAULT);
  curl_multi_cleanup(curl_handle);
 
  return 0;
}

output:

fetch https://www.baidu.com
create_curl_context(0x7ff5cbd00fd0, fd=11)
CURL_POLL_REMOVE: fd=11
create_curl_context(0x7ff5cbc0bb30, fd=11)
curl_close_socket: fd=11
CURL_POLL_REMOVE: fd=11
CURLMSG_DONE: ip::0 ssltime=36 time=46 

fetch https://www.baidu.com
curl_close_socket: fd=11
create_curl_context(0x7ff5cbe0a1f0, fd=12)
CURL_POLL_REMOVE: fd=12
CURLMSG_DONE: ip::0 ssltime=32 time=43 

fetch https://www.baidu.com
curl_close_socket: fd=12
create_curl_context(0x7ff5cbe129c0, fd=13)
CURL_POLL_REMOVE: fd=13
CURLMSG_DONE: ip::0 ssltime=39 time=50 

curl_close_socket: fd=13

It show socket closed at every call, and ssl session not working for domain: https:/www.baidu.com

If I remove CURLOPT_TCP_FASTOPEN, then the TLSv1.2 session cache is not get destroyed. but still close the socket every time.

fetch https://www.baidu.com
create_curl_context(0x7fefeac03d30, fd=11)
CURL_POLL_REMOVE: fd=11
create_curl_context(0x7fefeae002e0, fd=11)
curl_close_socket: fd=11
CURL_POLL_REMOVE: fd=11
CURLMSG_DONE: ip:180.101.49.12:443 ssltime=37 time=47 

fetch https://www.baidu.com
curl_close_socket: fd=11
create_curl_context(0x7fefeae00da0, fd=11)
CURL_POLL_REMOVE: fd=11
CURLMSG_DONE: ip:180.101.49.12:443 ssltime=0 time=10 

fetch https://www.baidu.com
curl_close_socket: fd=11
create_curl_context(0x7fefeaf090e0, fd=11)
CURL_POLL_REMOVE: fd=11
CURLMSG_DONE: ip:180.101.49.12:443 ssltime=0 time=10 

curl_close_socket: fd=11

the demo test on macOSX, linux, andoird. same results.

@bagder

This comment has been minimized.

Copy link
Member

@bagder bagder commented Sep 5, 2019

If it closes the connection or not is not relevant. Does it return the info if you remove CURLOPT_TCP_FASTOPEN ? Because that's an old unresolved bug, see #1332

@patrickkh7788

This comment has been minimized.

Copy link
Author

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

If it closes the connection or not is not relevant. Does it return the info if you remove CURLOPT_TCP_FASTOPEN ? Because that's an old unresolved bug, see #1332

Yes, I can get info without TFO.

The much important problem is with TFO tls session cache not working.

And the connection is not get reused like document said.

@patrickkh7788 patrickkh7788 changed the title CURLINFO_PRIMARY_IP, CURLINFO_PRIMARY_PORT empty for multi handle CURLINFO_PRIMARY_IP, CURLINFO_PRIMARY_PORT empty with CURLOPT_TCP_FASTOPEN Sep 5, 2019
@bagder

This comment has been minimized.

Copy link
Member

@bagder bagder commented Sep 5, 2019

The much important problem is with TFO tls session cache not working.

... which then sounds like a separate issue, right?

@patrickkh7788

This comment has been minimized.

Copy link
Author

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

The connection not get reused is a separate issue.

I am not sure the TLS cache is a separate issue, since it work as expect without TFO.

When do api call from China to EU or USA, the RTT is like 200ms to 2000ms, and tcp package get lost frequently. with TFO and 0-rtt TLSv1.3. the speed is get huge improve.

Without FASTOPEN, and a working TLS session cache, the ssl handshake time increased 2 ~ 3 times.

@bagder

This comment has been minimized.

Copy link
Member

@bagder bagder commented Sep 5, 2019

The way I read it, issue #4296 says that CURLINFO_PRIMARY_IP and CURLINFO_PRIMARY_PORT don't work with TFO enabled. Which unfortunately already was known since #1332, making this basically a duplicate.

Now you're talking about "TFO tls session cache not working" which is not mentioned at all in the previous paragraph, thus separate (but possibly related).

@patrickkh7788

This comment has been minimized.

Copy link
Author

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

Sorry for my poor English.

Correct me if I am wrong, I expect the curl work this way(by my understand from the document):

  1. connection get reused for easy handle with multi api. (in this test socket get closed for every call, before easy handle destroyed)

  2. TLS session cached when call same domain again (in this test, with TFO not working some times)

  3. CURLINFO_PRIMARY_IP and CURLINFO_PRIMARY_PORT should show correct information. (in this test with TFO show NULL)

@bagder

This comment has been minimized.

Copy link
Member

@bagder bagder commented Sep 5, 2019

All I'm asking is that we discuss one problem per issue. If you have more issues, then we discuss them in separate issues. Discussing numerous problems and theories in a single issue makes it hard to follow and understand what's going on.

@patrickkh7788

This comment has been minimized.

Copy link
Author

@patrickkh7788 patrickkh7788 commented Sep 5, 2019

Sorry for misunderstanding.

In here we can focus on CURLINFO_PRIMARY_IP and CURLINFO_PRIMARY_PORT with TFO return null problem.

@bagder bagder closed this in 8a9d6ee Dec 16, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.