|
|
cURL Mailing List Monthly Index Single Mail
curl-tracker mailing list Archives
[ curl-Bugs-1850730 ] Curl fails to call rewind during digest proxy authentication
From: SourceForge.net <noreply_at_sourceforge.net>
Date: Mon, 07 Jan 2008 11:34:31 -0800
Bugs item #1850730, was opened at 2007-12-14 13:13
Please note that this message will contain a full copy of the comment thread,
Initial Comment:
We are using curl 7.17.0
We try to post 376 bytes to a server, through a squid proxy configured for digest authentication. We find that curl does not call the ioctl rewind function (CURLIOCMD_RESTARTREAD) when it re-tries the post with correct authentication credentials.
This problem may be difficult to reproduce; on some machines it happens rarely, say 1 in 50, on other machines it will happen constantly. This has been seen on Linux and OS X platforms.
We can't as yet see where the problem may lie. Please see the log output below (with comments)
When our rewind function is called, "proto_input_stream::rewind" is seen in the log output; Similarly "proto_input_stream::read" are calls to our read function
16:43:14 url '192.168.100.204/Discovery/HTTPsvc/IISXferWanServer.DLL' proxy 'test:test_at_vm-fruitbat:3128'
/* Our data of length 376 */
16:43:14 CURL: About to connect() to proxy vm-fruitbat port 3128 (#0)
<..html error message...
/* Our "stream" is read here. Note that there is no rewind called afer these reads. */
16:43:14 CURL: Closing connection #0
/* Another read. Since no rewind has taken place it cannot be fulfilled */
16:43:15 proto_input_stream::read requested 16384 bytes
----------------------------------------------------------------------
>Comment By: Daniel Stenberg (bagder)
Message:
We're setting CURLOPT_POSTFIELDSIZE, so data->set.postfieldsize will be
It seems you're not using the CVS version as there's no code on
----------------------------------------------------------------------
Comment By: Spacen Jasset (sjasset)
Message:
Here is my debug session. Since we aren't calling CURLOPT_POSTFIELDS will
(gdb) run
Starting program: /home/user/curl/tests/libtest/.libs/lt-lib552
Breakpoint 2, Curl_http (conn=0x80637d0, done=0xbfa1f176) at http.c:2616
----------------------------------------------------------------------
Comment By: Daniel Stenberg (bagder)
Message:
I want to remain focused on creating a test case with the test suite that
In the test case 552 it sends 70000 bytes in a POST. At lib/http.c:2621,
Can you set a break-point on http.c:2620 for test case 552 and see why the
----------------------------------------------------------------------
Comment By: Spacen Jasset (sjasset)
Message:
I have tried breakpointing the expect100 continue message. The function
This is odd, and you are right in that the test case does call rewind. Why
I have prepared a squid proxy server on the internet, that, if you are
root_at_vm-fruitbat:~/curl/tests/data# diff -a test552.orig test552
--- > http://jason.spashett.com/cgi-bin/var.cgi http://test:test@ionrift.ath.cx:8080 ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-28 22:37 Message: Logged In: YES user_id=1110 Originator: NO Very interesting. But what's most interesting perhaps, is that the rewinding is done for you as the "stdout552" file shows in your tarball. So in fact, the POST operation is successful over the proxy doing Digest. What fails, is that your version of the lib552 client somehow doesn't send "Expect: 100-continue" in the request headers, and thus the comparison fails. I don't understand why! If you run the single test case with "./runtests.pl -g 552" you can set a break-point in lib/http.c:expect100() or possibly lib/http.c:2385 to see if you can understand why you don't get that header added in the request! ---------------------------------------------------------------------- Comment By: Spacen Jasset (sjasset) Date: 2007-12-28 15:21 Message: Logged In: YES user_id=1400532 Originator: YES I just ran test 552 and it failed on this system. 552_log_dir.tar.gz has been attached. root_at_vm-fruitbat:~/curl/tests# ./runtests.pl 552 ********* System characteristics ******** * curl 7.17.2-CVS (i686-pc-linux-gnu) * libcurl/7.17.2-CVS zlib/1.2.3.3 * Features: IPv6 Largefile libz * Host: vm-fruitbat * System: Linux vm-fruitbat 2.6.22-14-generic #1 SMP Sun Oct 14 23:05:12 GMT 2007 i686 GNU/Linux * Server SSL: OFF * libcurl SSL: OFF * libcurl debug: OFF * valgrind: ON * HTTP IPv6 ON * FTP IPv6 ON * HTTP port: 8990 * FTP port: 8992 * FTP port 2: 8995 * HTTP IPv6 port: 8994 * FTP IPv6 port: 8996 * TFTP port: 8997 * SCP/SFTP port: 8999 * SOCKS port: 9000 * Libtool lib: OFF ***************************************** test 552...[HTTP proxy auth Digest with 70K POST data from read callback] protocol FAILED: Binary files log/check-expected and log/check-generated differ - abort tests TESTDONE: 0 tests out of 1 reported OK: 0% TESTFAIL: These test cases failed: 552 TESTDONE: 1 tests were considered during 7 seconds. File Added: 552_log_dir.tar.gz ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-26 23:29 Message: Logged In: YES user_id=1110 Originator: NO I've now committed test case 552 which tests this, see the tests/libtest/lib552.c file for the exact source code - based on your test case. ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-25 23:56 Message: Logged In: YES user_id=1110 Originator: NO Ok, in my case the rewinding is done in the following way. It would be good to see if you could set a break-point in a suitable place and check why your example doesn't do this same thing! (backtrace from the ioctl callback) #0 ioctl_callback (handle=0x80b99ac, cmd=1, clientp=0x0) at lib552.c:143 #1 0x080623b5 in Curl_readrewind (conn=0x80cb5e4) at transfer.c:243 #2 0x0807dc34 in perhapsrewind (conn=0x80cb5e4) at http.c:344 #3 0x0807de20 in Curl_http_auth_act (conn=0x80cb5e4) at http.c:393 #4 0x0806316c in Curl_readwrite (conn=0x80cb5e4, done=0xbff203a3) at transfer.c:648 #5 0x08065814 in Transfer (conn=0x80cb5e4) at transfer.c:1773 #6 0x0806637d in Curl_perform (data=0x80b99ac) at transfer.c:2343 #7 0x0804f732 in curl_easy_perform (curl=0x80b99ac) at easy.c:498 And to clarify the process in English: In Curl_readwrite() it fins the auth stuff and calls Curl_http_auth_act(). In Curl_http_auth_act() it continues all the way down to line 393 where it calls perhapsrewind() and then in perhapsrewind() it sees that it really sent a lot of data so on http.c:344 it calls Curl_readrewind... ---------------------------------------------------------------------- Comment By: Spacen Jasset (sjasset) Date: 2007-12-23 01:11 Message: Logged In: YES user_id=1400532 Originator: YES I have tried it with the latest cvs version and I have attached another log. The same thing happens. I have also included a fprintf when rewind is called (previously it was a printf) The rewind isn't called according to my output. At the top of the log: Curl version: libcurl/7.17.2-CVS OpenSSL/0.9.8e zlib/1.2.3.3 libidn/1.0 I have run the unit tests with the lastest cvs version, and they all pass: TESTDONE: 333 tests out of 333 reported OK: 100% TESTDONE: 412 tests were considered during 739 seconds. TESTINFO: 79 tests were skipped due to these restraints: TESTINFO: "curl lacks any scp support" 4 times (601, 603, 605, 607) TESTINFO: "curl lacks SSL support" 22 times (94, 183, 184, 185, 300, 301, 302, 303, 304, 305, 306, 400, 401, 402, 403, 404, 405, 406, 407, 408, 409, 509) TESTINFO: "curl lacks any sftp support" 13 times (600, 602, 604, 606, 608, 609, 610, 611, 612, 613, 614, 615, 2004) TESTINFO: "rlimit problem: fds needed 1050 > system limit 1024" 1 times (518) TESTINFO: "curl lacks netrc_debug support" 6 times (130, 131, 132, 133, 134, 257) TESTINFO: "curl lacks OpenSSL support" 2 times (307, 308) TESTINFO: "failed starting SSH server" 6 times (700, 701, 702, 703, 706, 707) TESTINFO: "curl lacks idn support" 1 times (165) TESTINFO: "curl lacks NTLM support" 24 times (67, 68, 69, 70, 81, 89, 90, 91, 150, 155, 159, 162, 169, 170, 176, 209, 213, 239, 243, 265, 267, 547, 548, 1008) File Added: 1850730_cvs_latest.log ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-22 16:01 Message: Logged In: YES user_id=1110 Originator: NO Ok, then I must urge you to retry this with a recent CVS/daily snapshot version, since that is just about the exact thing I get with my tests and my tests work fine. You could also make sure the debug outputs in the ioctl() rewind action gets sent to stderr as then you should see that the stream is indeed rewinded at the end of the first post. At least it is for me. ---------------------------------------------------------------------- Comment By: Spacen Jasset (sjasset) Date: 2007-12-22 14:34 Message: Logged In: YES user_id=1400532 Originator: YES Please find attached a debug log from curl using squid as a proxy. File Added: 1850730_through_squid.log ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-21 23:01 Message: Logged In: YES user_id=1110 Originator: NO I have no desire to get, install and configure squid to get a digest-proxy just for testing this. It is a lot easier if you'd simply provide the detailed log your own test program provides. Please? I created a test case with your code exactly, and it behaves just fine with the test suite's digest proxy so there's clearly something different between that and the squid (config) you use! ---------------------------------------------------------------------- Comment By: Spacen Jasset (sjasset) Date: 2007-12-21 15:33 Message: Logged In: YES user_id=1400532 Originator: YES Please see attached tar file containing source code to reproduce problem. We are using a squid proxy (Version 2.6.STABLE14) with digest auth enabled. Our test program has been run on ubuntu 7.10, but the problem is not specific to this platform. run the program with a proxy as an argument: ./debug test:test_at_vm-fruitbat:3128 2>&1 | tee out The program should hang forever when it retries the request with proper authentication credentials. File Added: 1850730.tar.gz ---------------------------------------------------------------------- Comment By: Spacen Jasset (sjasset) Date: 2007-12-19 12:48 Message: Logged In: YES user_id=1400532 Originator: YES Our application is using curl more or less like that posted. I have not had the chance to reproduce this yet, but will do so when I can get around to it. Our temporary fix is working for us at the moment. ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-15 23:14 Message: Logged In: YES user_id=1110 Originator: NO Anyway, in an attempt to reproduce this report I wrote up and committed test case 551, although it seems to do what it should... ---------------------------------------------------------------------- Comment By: Daniel Stenberg (bagder) Date: 2007-12-15 22:39 Message: Logged In: YES user_id=1110 Originator: NO And your application is more or less like this: http://curl.haxx.se/lxr/source/tests/libtest/lib547.c ? ---------------------------------------------------------------------- You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=100976&aid=1850730&group_id=976Received on 2008-01-07 These mail archives are generated by hypermail. |
Page updated November 12, 2010.
web site info