Bugs item #2111613, was opened at 2008-09-15 08:33
Message generated for change (Settings changed) made by bagder
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=2111613&group_id=976

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: libcurl
Group: hang
>Status: Closed
Resolution: Fixed
Priority: 5
Private: No
Submitted By: Igor (ketamin)
Assigned to: Daniel Stenberg (bagder)
Summary: multi object is stuck

Initial Comment:
Configuration
-------------
libcurl/7.18.2 OpenSSL/0.9.8h zlib/1.2.3 Windows XP/SP2

Application
-----------
My application is a single-thread client application
that accesses XCAP server in order to manipulate documents
stored on it.
The application uses 'multi' and curl_multi_socket() API
in order to work asynchronously.

Scenario
--------
The application performs following transactions in sequential order:
1. PUT-401-PUT-500 - trial to create doc on server
2. PUT-401-PUT-500 - trial to modify doc on server
3. GET-401-GET-500 - trial to fetch doc from server
4. POST-401-POST-500 - trial to search on server
5. DELETE-401-DELETE-500 - trial to delete doc

All transactions share same 'multi' object.
Each of transactions use dedicated 'easy' object.
Same 'easy' object is used for both original request and
for next authorization retrial request:
on receiving 401 the 'easy' is removed for the 'multi',
the username/password are set into it,
and it is added back to the 'multi' again.

Problem
-------
Sometimes after the 'easy' is added back to the 'multi'
in order to send authorized request nothing happens -> the application is stuck.

Logs

----
To my sorrow the problem doesn't appear when debugging info is printed.
Therefore I added 'printf'-s into the all libcurl API functions/callbacks
used/implemented by the application.
At the begining of the attached file you can see snip of the full log,
where the last good transaction and the next to it bad transaction are logged.
After snip the full log appears.
As it can be seen from the log,
the call to last curl_multi_add_handle() doesn't initiate any activity,
because 'timer_lastcall' is equeal to the 'multi->timetree->key'.
Is there any chance that the millisecond timer resolution is not enough?
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-10-15 09:42
Message:
Thank you for compliment, but...
1. I don't deserve the credit since both the problem root discovery and
problem solution was made by you.
2. I would prefer to stay in shadow. 
Anyway if you need my name - Igor Novoseltsev
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Date: 2008-10-15 09:35
Message:
I've committed a fix for this flaw now (only slightly different than
discussed here). If you give me your full name I'll make sure to five you
the proper credit in the changelog.
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-10-06 10:26
Message:
The proposed fix works good.
I failed to reproduce the problem with the latest 7.19.1.
That is why it took me a time to get back to you.
But I successfully reproduced it and verified fix with the 7.18.2.
Respectfully yours,
Igor
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Date: 2008-10-05 23:34
Message:
Ok, you have to clear the struct and not just assign a zero. Can you please
try this? I think it is the correct approach, or we should rather make the
update_timer() get a "force" option but it would be good to get a
confirmation first that it actually fixes the problem.
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Date: 2008-09-29 14:34
Message:
As a test, can you try to set:
  multi->timer_lastcall = 0;
Just before the call to update_timer() with the curl_multi_remove_handle()
function? (lib/multi.c:695 in my version)
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Date: 2008-09-29 14:28
Message:
Then I think the problem is that multi->timer_lastcall is still being set
when the timer is removed as it is supposed to only prevent a duplicate
being reported so if there's no active timer in the application it should
probably be cleared...
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-09-24 07:42
Message:
Hello Daniel,
sorry for delayed response, I was quite busy.
According the following snippet of the log:
APP: REQ 01130F50: NEW_REQUEST
CURL:curl_multi_add_handle(multi=010859D0,easy=0129D438)
CURL:update_timer: key=91123:157000, timer_lastcall=91123:126000
CurlCB_timer: ask 1 msec
APP: SEARCH_DOCUMENT operation was initiated.
CurlCB_timer: got
CURL:curl_multi_remove_handle(multi=010859D0,easy=0129D438)
APP: REQ 01130F50: CREDENTIALS
CURL:curl_multi_add_handle(multi=010859D0,easy=0129D438)
CURL:update_timer: key=91123:157000, timer_lastcall=91123:157000
You can see that the last sequence of remove_handle and add_handle
(easy=0129D438) was made when no application timer run. The sequence was
probably performed in less than millisecond, causing the libcurl not to ask
next timer.
With Respect,
Igor
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Date: 2008-09-21 23:49
Message:
The timer callback tells the application about a single timer for the multi
handle, why would it be a problem for anything if a second callback
indicating the exact same time is prevented to get called? I don't think
that's the cause of these problems.
----------------------------------------------------------------------
Comment By: Dan Fandrich (dfandrich)
Date: 2008-09-16 16:59
Message:
Those are plain text files with troff 'man' macros, so any text editor will
do. I'm not aware of a WYSIWYG editor for troff, but there may be one.
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-09-16 10:19
Message:
Could you so kind to recommend editor for .3 files?
----------------------------------------------------------------------
Comment By: Dan Fandrich (dfandrich)
Date: 2008-09-16 08:46
Message:
The .pdf and .html files are generated from the .3 files, so just the
latter needs to be updated in a patch. For reference, the user:password
issue is KNOWN_BUGS #7, and a patch for that would be welcome.
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-09-16 07:59
Message:
Hi Dan,
please disregard my previous mail,
I found the asked doc
(http://curl.haxx.se/docs/contribute.html#How_To_Make_a_Patch)
when started to read coding conventions before developing a patch :)
(May be it worth it to devote a separate page to the How_To_Make_a_Patch
subject).
I'm going to submit 2 patches soon.
Could you kindly clarify the patch for documentation issue?
Where can I found format of ASCII document that is converted automatically
into HTML/PDF? I'm going to add new options to curl_easy_setopt() API.
----------------------------------------------------------------------
Comment By: Igor (ketamin)
Date: 2008-09-16 07:03
Message:
Hi Dan,
Thanks for reply!
I'd failed to find something usable in mailing list.
Therefore I would like to submit a patch based on
QueryPerformanceFrequency/QueryPerformanceCounter API. It provides even
nanosecond resolution that should be definitely enough for near future.
Could you address me to some doc that explain the patch submitting
process?
I dug in http://curl.haxx.se/docs/ and in gmane.comp.web.curl.library but
without success. Should I simply post the output of 'diff' to the mailing
list?
One more question. I would like to submit another patch, which separates
username and password options for curl_easy_setopt() in order to enable
colon in username (in order to pass Digest authentication). Should I
provide patch for curl_easy_setopt.pdf, curl_easy_setopt.3 and
curl_easy_setopt.html documentation files also?
Thank you very much in advance,
Igor
----------------------------------------------------------------------
Comment By: Dan Fandrich (dfandrich)
Date: 2008-09-15 18:55
Message:
As I recall, the timer resolution was improved to microsecond resolution in
7.18.2 to prevent problems like this. You may want to bring this problem to
the curl-library mailing list so the Windows developers can suggest a way
to bring microsecond resolution to the Windows port.
----------------------------------------------------------------------
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=2111613&group_id=976