Buy commercial curl support. We
help you work out your issues, debug your libcurl applications, use the API,
port to new platforms, add new features and more. With a team lead by the
curl founder Daniel himself.
Re: When using ActiveMode of FTPS on Curl for Windows, it takes polling timeout time (1000msec) to establish DataConnection.
- Contemporary messages sorted: [ by date ] [ by thread ] [ by subject ] [ by author ] [ by messages with attachments ]
From: Stefan Eissing via curl-library <curl-library_at_lists.haxx.se>
Date: Wed, 4 Sep 2024 16:09:07 +0200
> Am 04.09.2024 um 15:20 schrieb Yoshimasa Ohno <momontyo_at_gmail.com>:
>
> Okay.
>
> I was able to reproduce it with '--trace-time --trace-config all'.
> (full command: 'curl --ftp-port - --ssl-reqd -u Anonymous: ftp://127.0.0.1/ -k --trace-time --trace-config all --trace trace-log2.txt')
>
> Attached is the trace file.
>
> ---- Excerpt lines 450-460.
> 22:10:18.797429 [0-0] == Info: Preparing for accepting server on data port
> 22:10:18.797432 [0-0] == Info: Checking for server connect
> 22:10:18.797437 [0-0] == Info: [FTP] AllowServerConnect() -> 0
> 22:10:18.797439 [0-0] == Info: Data conn was not available immediately
> 22:10:18.797441 [0-0] == Info: [FTP] [LIST] -> [STOP]
> 22:10:18.797443 [0-0] == Info: Checking for server connect
> 22:10:18.797447 [0-0] == Info: [FTP] [STOP] ftp_domore_getsock()
> 22:10:19.808368 [0-0] == Info: Checking for server connect
> 22:10:19.808411 [0-0] == Info: Ready to accept data connection from server
> 22:10:19.808651 [0-0] == Info: Connection accepted from server
> 22:10:19.808772 [0-0] == Info: [TCP-ACCEPT-1] accepted_set(sock=508, remote=127.0.0.1 port=63175)
> ----
>
> Here you can see that it is weighted for 1 second
Thank you! I found the condition that prevented my former fix to be working. I made https://github.com/curl/curl/pull/14786 with the real solution which I was able to verify with some new test cases. Hope this works for you as well!
- Stefan
>
>
> 2024年9月4日(水) 20:59 Stefan Eissing <stefan_at_eissing.org>:
>
>
> > Am 04.09.2024 um 13:41 schrieb Yoshimasa Ohno via curl-library <curl-library_at_lists.haxx.se>:
> >
> > Thanks for the response!
> >
> > I tried a local build including
> > https://github.com/curl/curl/commit/a07ba37b5e88a89bf4bcc6b0c927f7a42d7ea4f2
> > Unfortunately, it did not solve the problem I am experiencing in my environment.
> >
> > Even just adding printf debugging.
> > I don't know where the real cause is, because the problem is no longer reproduced.
> >
> > One of the conditions for the occurrence of the Dalay problem seems to be that the ReceivedServerConnect function exits in the socket unestablished state.
> > ReceivedServerConnect function seems to occur when the following, unestablished state comes through.
> > https://github.com/curl/curl/blob/6a9b71037a441eac28d3c7f629ac5801c01f99e2/lib/ftp.c#L572C1-L573C22
> > case 0: /* Server connect is not received yet */
> > break; /* loop */
> >
> > When a problem occurs, there is a delay of timeout time (standard is 1 second, extended that way if modified) in the following WSAWaitForMultipleEvents.
> > https://github.com/curl/curl/blob/6a9b71037a441eac28d3c7f629ac5801c01f99e2/lib/multi.c#L1366
> > else { /* now wait... if not ready during the pre-check (pollrc == 0) */
> > WSAWaitForMultipleEvents(1, &multi->wsa_event, FALSE, (DWORD)timeout_ms,
> > FALSE);
> > }
> >
> > Is there anything I can try?
>
> Can you produce a log file via 'curl -v --trace-config all' of such a situation?
>
> As you describe it, the delay happens when the first check on the listening socket does
> not find anything and curl goes POLLing for socket events. The arriving server connect
> should then trigger the processing right away, but maybe there is something else in play here.
>
> - Stefan
>
> > 2024年9月3日(火) 16:59 Stefan Eissing via curl-library <curl-library_at_lists.haxx.se>:
> > I created https://github.com/curl/curl/pull/14766 as a fix for this.
> >
> > The bug was that the socket was not using POLLIN, but POLLOUT. So it never
> > triggered an event when the FTP server tried to connect. That led to the
> > connect only being noticed a second later when curl checks on all transfers.
> >
> > Hope this works for you.
> >
> >
> > > Am 03.09.2024 um 08:13 schrieb Daniel Stenberg via curl-library <curl-library_at_lists.haxx.se>:
> > >
> > > On Sat, 31 Aug 2024, Yoshimasa Ohno via curl-library wrote:
> > >
> > >> I found that the timeout argument of curl_multi_poll, the literal 1000, was having an effect. Changing this to 3000 resulted in a 3 second wait.
> > >
> > > We believe there might be a bug in the code that sets what socket activity curl should wait for when waiting for the connect to happen. (A regression)
> > >
> > > Stefan is going to try to get a fix made and submitted soon.
> > >
> > > --
> > >
> > > / daniel.haxx.se
> > > | Commercial curl support up to 24x7 is available!
> > > | Private help, bug fixes, support, ports, new features
> > > | https://curl.se/support.html
> > > --
> > > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > > Etiquette: https://curl.se/mail/etiquette.html
> >
> > --
> > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > Etiquette: https://curl.se/mail/etiquette.html
> > --
> > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > Etiquette: https://curl.se/mail/etiquette.html
>
> <trace-log2.txt>
Date: Wed, 4 Sep 2024 16:09:07 +0200
> Am 04.09.2024 um 15:20 schrieb Yoshimasa Ohno <momontyo_at_gmail.com>:
>
> Okay.
>
> I was able to reproduce it with '--trace-time --trace-config all'.
> (full command: 'curl --ftp-port - --ssl-reqd -u Anonymous: ftp://127.0.0.1/ -k --trace-time --trace-config all --trace trace-log2.txt')
>
> Attached is the trace file.
>
> ---- Excerpt lines 450-460.
> 22:10:18.797429 [0-0] == Info: Preparing for accepting server on data port
> 22:10:18.797432 [0-0] == Info: Checking for server connect
> 22:10:18.797437 [0-0] == Info: [FTP] AllowServerConnect() -> 0
> 22:10:18.797439 [0-0] == Info: Data conn was not available immediately
> 22:10:18.797441 [0-0] == Info: [FTP] [LIST] -> [STOP]
> 22:10:18.797443 [0-0] == Info: Checking for server connect
> 22:10:18.797447 [0-0] == Info: [FTP] [STOP] ftp_domore_getsock()
> 22:10:19.808368 [0-0] == Info: Checking for server connect
> 22:10:19.808411 [0-0] == Info: Ready to accept data connection from server
> 22:10:19.808651 [0-0] == Info: Connection accepted from server
> 22:10:19.808772 [0-0] == Info: [TCP-ACCEPT-1] accepted_set(sock=508, remote=127.0.0.1 port=63175)
> ----
>
> Here you can see that it is weighted for 1 second
Thank you! I found the condition that prevented my former fix to be working. I made https://github.com/curl/curl/pull/14786 with the real solution which I was able to verify with some new test cases. Hope this works for you as well!
- Stefan
>
>
> 2024年9月4日(水) 20:59 Stefan Eissing <stefan_at_eissing.org>:
>
>
> > Am 04.09.2024 um 13:41 schrieb Yoshimasa Ohno via curl-library <curl-library_at_lists.haxx.se>:
> >
> > Thanks for the response!
> >
> > I tried a local build including
> > https://github.com/curl/curl/commit/a07ba37b5e88a89bf4bcc6b0c927f7a42d7ea4f2
> > Unfortunately, it did not solve the problem I am experiencing in my environment.
> >
> > Even just adding printf debugging.
> > I don't know where the real cause is, because the problem is no longer reproduced.
> >
> > One of the conditions for the occurrence of the Dalay problem seems to be that the ReceivedServerConnect function exits in the socket unestablished state.
> > ReceivedServerConnect function seems to occur when the following, unestablished state comes through.
> > https://github.com/curl/curl/blob/6a9b71037a441eac28d3c7f629ac5801c01f99e2/lib/ftp.c#L572C1-L573C22
> > case 0: /* Server connect is not received yet */
> > break; /* loop */
> >
> > When a problem occurs, there is a delay of timeout time (standard is 1 second, extended that way if modified) in the following WSAWaitForMultipleEvents.
> > https://github.com/curl/curl/blob/6a9b71037a441eac28d3c7f629ac5801c01f99e2/lib/multi.c#L1366
> > else { /* now wait... if not ready during the pre-check (pollrc == 0) */
> > WSAWaitForMultipleEvents(1, &multi->wsa_event, FALSE, (DWORD)timeout_ms,
> > FALSE);
> > }
> >
> > Is there anything I can try?
>
> Can you produce a log file via 'curl -v --trace-config all' of such a situation?
>
> As you describe it, the delay happens when the first check on the listening socket does
> not find anything and curl goes POLLing for socket events. The arriving server connect
> should then trigger the processing right away, but maybe there is something else in play here.
>
> - Stefan
>
> > 2024年9月3日(火) 16:59 Stefan Eissing via curl-library <curl-library_at_lists.haxx.se>:
> > I created https://github.com/curl/curl/pull/14766 as a fix for this.
> >
> > The bug was that the socket was not using POLLIN, but POLLOUT. So it never
> > triggered an event when the FTP server tried to connect. That led to the
> > connect only being noticed a second later when curl checks on all transfers.
> >
> > Hope this works for you.
> >
> >
> > > Am 03.09.2024 um 08:13 schrieb Daniel Stenberg via curl-library <curl-library_at_lists.haxx.se>:
> > >
> > > On Sat, 31 Aug 2024, Yoshimasa Ohno via curl-library wrote:
> > >
> > >> I found that the timeout argument of curl_multi_poll, the literal 1000, was having an effect. Changing this to 3000 resulted in a 3 second wait.
> > >
> > > We believe there might be a bug in the code that sets what socket activity curl should wait for when waiting for the connect to happen. (A regression)
> > >
> > > Stefan is going to try to get a fix made and submitted soon.
> > >
> > > --
> > >
> > > / daniel.haxx.se
> > > | Commercial curl support up to 24x7 is available!
> > > | Private help, bug fixes, support, ports, new features
> > > | https://curl.se/support.html
> > > --
> > > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > > Etiquette: https://curl.se/mail/etiquette.html
> >
> > --
> > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > Etiquette: https://curl.se/mail/etiquette.html
> > --
> > Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library
> > Etiquette: https://curl.se/mail/etiquette.html
>
> <trace-log2.txt>
-- Unsubscribe: https://lists.haxx.se/mailman/listinfo/curl-library Etiquette: https://curl.se/mail/etiquette.htmlReceived on 2024-09-04