Malcolm Matalka <malc...@terrateam.io> writes:
> Malcolm Matalka <malc...@terrateam.io> writes: > >> Hello, I'm debugging a bug in my program using the multi interface. I'm >> still >> trying to work out some details but I thought maybe someone who knows the >> codebase better than I might just see it as obvious. >> >> In my case, I am setting SOCKETFUNCTION, TIMERFUNCTION, and >> CLOSESOCKETFUNCTION >> because I need to manage the sockets myself (I'm integrating curl against a >> concurrency library in Ocaml). Because of how the concurrency library works, >> instead of doing any work in those callbacks functions, I'm adding the event >> to >> a queue then processing the events after a "perform" or "action" call. >> >> What I'm seeing is that I have a POLL_REMOVE call for a socket, but then my >> CLOSESOCKETFUNCTION callback is not being called. I can see in the ktrace >> logs that the socket is directly being closed with "close". >> >> I *think* this is happening due libcurl deciding the connection has timed out >> and some logic chooses not to execute the close callback. But I'm not >> entirely sure. >> >> Any idea how I can turn on the tracing for cf-socket.c? I have set the >> global >> trace to 'all' but I am not seeing the logs I am looking for? >> >> I am on FreeBSD use curl 8.11.1. >> >> Thank you >> >> /Malcolm > > After learning some lldb, this is what I got. Here is the log from my > application (I log on timerfunction, socketfunction, and closefunction). > Lines starting with '#' are my annotations to expalin > > > # We receive timeout for 1 ms > timeout_function : 1 > still_running : 1 > > firing timeout > timeout > # We receive sockketfunction call for poll_in on fd 5. This adds the event > to our queue > socket_function : poll_in : 5 > # Setup new timeout > timeout_function : 2 > # execute a perform > perform > still_running : 1 > > # This is the queue handler processing the queue > socket : poll_in : 5 > # Async wait on 5 > wait fd : 5 > > # we've timed out > firing timeout > timeout > timeout_function : 1 > perform > still_running : 1 > > firing timeout > timeout > > # update timeout > timeout_function : 8 > perform > timeout_function : 8 > still_running : 1 > > # Fire timeout > firing timeout > timeout > > # We see now poll_remove for fd 5, this adds handling the poll_remove to the > queue > socket_function : poll_remove : 5 > > Now, I would expect to see a "close_function" message here as we get a close, > however we do not. I added a breakpoint in lldb to print the backgroud out > on any call to close and I can see that libcurl is calling close right after > the poll_remove. > > * frame #0: 0x00000008257d23c8 libc.so.7`close(fd=5) at close.c:43:10 > frame #1: 0x00000008231fda0a > libcurl.so.4`destroy_async_data(async=0x00001c8252225620) at > asyn-thread.c:433:5 > frame #2: 0x00000008231fdbca > libcurl.so.4`Curl_resolver_is_resolved(data=0x00001c8252224800, > entry=0x0000000820e163f8) at asyn-thread.c:612:5 > frame #3: 0x0000000823229205 > libcurl.so.4`Curl_resolv_check(data=0x00001c8252224800, > dns=0x0000000820e163f8) at hostip.c:1409:12 > frame #4: 0x000000082324be96 libcurl.so.4`multi_runsingle [inlined] > state_resolving(multi=0x00001c82521e5000, data=0x00001c8252224800, > stream_errorp=0x0000000820e163eb, resultp=0x0000000820e163f0) at > multi.c:2502:14 > frame #5: 0x000000082324be8a > libcurl.so.4`multi_runsingle(multi=0x00001c82521e5000, > nowp=0x0000000820e164f8, data=0x00001c8252224800) at multi.c:2681:12 > frame #6: 0x000000082324f3f8 > libcurl.so.4`multi_run_expired(mrc=0x0000000820e164f0) at multi.c:3510:14 > frame #7: 0x000000082324d9f2 > libcurl.so.4`multi_socket(multi=0x00001c82521e5000, checkall=<unavailable>, > s=<unavailable>, ev_bitmask=<unavailable>, > running_handles=0x0000000820e16604) at multi.c:3601: > 12 > frame #8: 0x000000082324db6c > libcurl.so.4`curl_multi_socket_action(m=<unavailable>, s=<unavailable>, > ev_bitmask=<unavailable>, running_handles=<unavailable>) at multi.c:3727:10 > [artificial] > frame #9: 0x0000000000424af0 > abb_curl_cli.native`caml_curl_multi_socket_action(v_multi=35172246200, > v_fd=1, v_kind=1) at curl-helper.c:4981:10 > > Also, I do feel confident that the CLOSEFUNCTION behaviour does work because > I see it working in other contexts. > > If I understand what is happening here correctly, I believe this block of > code should not call "wakeup_close" (which is defined as "close" in my > environment) but instead should check if the close callback is defined and > call that instead. > > https://github.com/curl/curl/blob/curl-8_11_1/lib/asyn-thread.c#L426-L431 > > Is that correct? Sorry to spam, but I think my understanding is not entirely correct. I believe this is a socket that curl (or the multi interface in particular?) is using for its own needs, and it's not necessarily part of a handle. The opensocket and closesocket callbacks are for a handle, which means they do not get called in this case. The issue with my usage is that despite opensocket and closesocket not being called, the socketfunction callback is called to manage polling, however due to some constraints on my system, I cannot actually do the socketfunction callback work in the callback, but I think curl assumes it can, in which case it believes its safe to call close on the socket after the POLL_REMOVE. The reason I can using CLOSESOCKET in a handle is because I need to be back in my program's control flow to do some cleanup before actually closing the socket. Is my understanding correct? I understand this might be an unexpected usage of libcurl, but are there any suggested workarounds? > > Thank you -- Malcolm Matalka Terrateam -- Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library Etiquette: https://curl.se/mail/etiquette.html
