I added simple logging and a debug function to the following Boost ASIO-based example program:

https://curl.haxx.se/libcurl/c/asiohiper.html

Summary:

1) In the WAITCONNECT state, libcurl calls multi_timer_cb(200) and registers interest in writing.
2) The FSM transitions first to SENDPROTOCONNECT and then to PROTOCONNECT.
3) Libcurl calls remsock() through sock_cb().
4) ... Nothing happens until the timer fires ~165 ms later.

What should the example do, if possible, to avoid this delay? I appreciate any ideas/clues/hints. Until then, I'm investigating the differences between this and the other example programs.

I'm including the log (trimmed to point of interest) below:

2018-05-17 21:06:11,461 INFO  root - opensocket:
2018-05-17 21:06:11,461 INFO  root - from libcurl:   Trying 172.217.12.4...
2018-05-17 21:06:11,461 INFO  root - from libcurl: TCP_NODELAY set
2018-05-17 21:06:11,461 INFO  root - from libcurl: STATE: WAITRESOLVE => WAITCONNECT handle 0x1d97188; line 1539 (connection #0)
2018-05-17 21:06:11,461 INFO  root - sock_cb (sock=6, what=2)
2018-05-17 21:06:11,461 INFO  root - sock_cb: adding data: OUT
2018-05-17 21:06:11,461 INFO  root - addsock (action=2)
2018-05-17 21:06:11,461 INFO  root - setsock (sock=6, action=2, oldact=0)
2018-05-17 21:06:11,461 INFO  root - setsock: watching for socket to become writable
2018-05-17 21:06:11,461 INFO  root - multi_timer_cb (timeout_ms=200)
2018-05-17 21:06:11,461 INFO  root - check_multi_info; remaining=1
2018-05-17 21:06:11,494 INFO  root - event_cb (sock=6, action=2)
2018-05-17 21:06:11,494 INFO  root - event_cb: running multi socket action
2018-05-17 21:06:11,494 INFO  root - from libcurl: Connected to www.google.com (172.217.12.4) port 80 (#0)
2018-05-17 21:06:11,494 INFO  root - from libcurl: STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x1d97188; line 1591 (connection #0)
2018-05-17 21:06:11,494 INFO  root - from libcurl: Marked for [keep alive]: HTTP default
2018-05-17 21:06:11,494 INFO  root - from libcurl: STATE: SENDPROTOCONNECT => PROTOCONNECT handle 0x1d97188; line 1605 (connection #0)
2018-05-17 21:06:11,494 INFO  root - sock_cb (sock=6, what=4)
2018-05-17 21:06:11,494 INFO  root - remsock
2018-05-17 21:06:11,494 INFO  root - check_multi_info; remaining=1
2018-05-17 21:06:11,494 INFO  root - event_cb: keep watching...?
2018-05-17 21:06:11,662 INFO  root - timer_cb:
2018-05-17 21:06:11,662 INFO  root - from libcurl: STATE: PROTOCONNECT => DO handle 0x1d97188; line 1626 (connection #0)
2018-05-17 21:06:11,662 INFO  root - from libcurl: STATE: DO => DO_DONE handle 0x1d97188; line 1688 (connection #0)
2018-05-17 21:06:11,662 INFO  root - from libcurl: STATE: DO_DONE => WAITPERFORM handle 0x1d97188; line 1813 (connection #0)
2018-05-17 21:06:11,662 INFO  root - from libcurl: STATE: WAITPERFORM => PERFORM handle 0x1d97188; line 1823 (connection #0)
2018-05-17 21:06:11,662 INFO  root - sock_cb (sock=6, what=1)
2018-05-17 21:06:11,662 INFO  root - sock_cb: adding data: IN
2018-05-17 21:06:11,662 INFO  root - addsock (action=1)
2018-05-17 21:06:11,662 INFO  root - setsock (sock=6, action=1, oldact=0)
2018-05-17 21:06:11,662 INFO  root - setsock: watching for socket to become readable
2018-05-17 21:06:11,662 INFO  root - multi_timer_cb (timeout_ms=1000)
2018-05-17 21:06:11,662 INFO  root - check_multi_info; remaining=1

Thanks,
Sean M.

-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html
Received on 2018-05-17