cURL / Mailing Lists / curl-library / Single Mail

curl-library

Race condition in test 564 after 4a42e5cdaa344755?

From: Fabian Keil <freebsd-listen_at_fabiankeil.de>
Date: Wed, 17 Aug 2011 01:06:06 +0200

I'm currently experimenting with the tests again, and one of the
issues I ran into (using 4ed7abb5370a9416) is that test 564 seems
to fail most of the time, but not always.

When it fails, I get:

fk_at_r500 ~/git/curl/tests $./runtests.pl -n 564
Use of uninitialized value $p in string eq at /usr/local/lib/perl5/5.14.1/BSDPAN/BSDPAN.pm line 36.
********* System characteristics ********
* curl 7.22.0-DEV (amd64-unknown-freebsd9.0)
* libcurl/7.22.0-DEV OpenSSL/0.9.8q zlib/1.2.5
* Features: Debug TrackMemory IPv6 Largefile NTLM NTLM_SSO SSL libz
* Host: r500.local
* System: FreeBSD r500.local 9.0-BETA1 FreeBSD 9.0-BETA1 #344 r+ea7f16f: Tue Aug 16 19:09:41 CEST 2011 fk_at_r500.local:/usr/obj/usr/src/sys/ZOEY amd64
* Server SSL: OFF libcurl SSL: ON
* debug build: ON track memory: ON
* valgrind: OFF HTTP IPv6 ON
* FTP IPv6 ON Libtool lib: OFF
* Shared build: no
* SSL library: OpenSSL
* Ports:
* HTTP/8990 FTP/8992 FTP2/8995 RTSP/9007
* TFTP/8997 HTTP-IPv6/8994 RTSP-IPv6/9008 FTP-IPv6/8996
* GOPHER/9009 GOPHER-IPv6/9009
* SSH/8999 SOCKS/9000 POP3/9001 IMAP/9003 SMTP/9005
* POP3-IPv6/9002 IMAP-IPv6/9004 SMTP-IPv6/9006
*****************************************
Use of uninitialized value $p in string eq at /usr/local/lib/perl5/5.14.1/BSDPAN/BSDPAN.pm line 36.
test 564...[FTP RETR a file over a SOCKS proxy using the multi interface]

 stdout FAILED:
--- log/check-expected 2011-08-17 00:05:29.722035830 +0200
+++ log/check-generated 2011-08-17 00:05:29.721032141 +0200
@@ -1,6 +0,0 @@
-data
- to
- see
-that FTP
-works
- so does it?

 - abort tests
TESTDONE: 0 tests out of 1 reported OK: 0%
TESTFAIL: These test cases failed: 564
TESTDONE: 1 tests were considered during 34 seconds.

---------

=== Start of file stderr564
 URL: ftp://127.0.0.1:8992/path/564
 Start at URL 0
 * About to connect() to proxy 127.0.0.1 port 9000 (#0)
 * Trying 127.0.0.1... * 0x80183e008 is at send pipe head
 * STATE: CONNECT => WAITCONNECT handle 0x8018c4088; (connection #0)
 * SOCKS4 request granted.
 * Connected to 127.0.0.1 (127.0.0.1) port 9000 (#0)
 * FTP 0x8019578f8 state change from STOP to WAIT220
 * STATE: WAITCONNECT => PROTOCONNECT handle 0x8018c4088; (connection #0)
 < 220- _ _ ____ _
 < 220- ___| | | | _ \| |
 < 220- / __| | | | |_) | |
 < 220- | (__| |_| | _ <| |___
 < 220 \___|\___/|_| \_\_____|
> USER anonymous
 * FTP 0x8019578f8 state change from WAIT220 to USER
 < 331 We are happy you popped in
> PASS ftp_at_example.com
 * FTP 0x8019578f8 state change from USER to PASS
 < 230 Welcome you silly person
> PWD
 * FTP 0x8019578f8 state change from PASS to PWD
 < 257 "/" is current directory
 * Entry path is '/'
 * FTP 0x8019578f8 state change from PWD to STOP
 * protocol connect phase DONE
 * STATE: PROTOCONNECT => DO handle 0x8018c4088; (connection #0)
 * DO phase starts
> CWD path
 * FTP 0x8019578f8 state change from STOP to CWD
 * STATE: DO => DOING handle 0x8018c4088; (connection #0)
 < 250 CWD command successful.
> EPSV
 * FTP 0x8019578f8 state change from CWD to PASV
 * Connect data stream passively
 < 229 Entering Passive Mode (|||53212|)
 * Trying 127.0.0.1... * Connecting to 127.0.0.1 (127.0.0.1) port 9000
 * SOCKS4 request granted.
 * FTP 0x8019578f8 state change from PASV to STOP
 * DO phase is complete
 * STATE: DOING => DO_MORE handle 0x8018c4088; (connection #0)
 * SOCKS4 reply has wrong version, version should be 4.: 500 '#
 * STATE: DO_MORE => COMPLETED handle 0x8018c4088; (connection #-5000)
 * STATE: COMPLETED => MSGSENT handle 0x8018c4088; (connection #-5000)
 * Closing connection #0
=== End of file stderr564

I locally modified socks.c like this, to dump the offending response:

diff --git a/lib/socks.c b/lib/socks.c
index ac13ed8..a351ddf 100644
--- a/lib/socks.c
+++ b/lib/socks.c
@@ -277,7 +277,10 @@ CURLcode Curl_SOCKS4(const char *proxy_name,
     /* wrong version ? */
     if(socksreq[0] != 0) {
       failf(data,
- "SOCKS4 reply has wrong version, version should be 4.");
+ "SOCKS4 reply has wrong version, version should be 4.:"
+ " %c%c%c%c%c%c%c%c",
+ socksreq[0], socksreq[1], socksreq[2], socksreq[3],
+ socksreq[4], socksreq[5], socksreq[6], socksreq[7]);
       return CURLE_COULDNT_CONNECT;
     }

It always seems to complain about the same byte sequence.
For one reason or another, curl seems to be interpreting an
ftp message as socks reply:

fk_at_r500 ~/git/curl/tests $grep -n "500 '" ./ftpserver.pl
1522: sendcontrol "500 '$_': command not understood.\r\n";

I confirmed this by modifying the error code.

Whether it fails or not, the test run seems to take about
34 seconds.

After reverting the lib/connect.c and lib/multi.c modifications
from 4a42e5cdaa344755c, while keeping the other modifications,
the test worked five times in a row.

Otherwise the success rate seems to be about 20% so even getting
two successes in a row is unlikely.

The patch is attached to make it more clear what I'm talking
about, I'm not suggesting that this is the solution.

Fabian

-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html

Received on 2011-08-17