cURL
Haxx ad
libcurl

curl's project page on SourceForge.net

Sponsors:
Haxx

cURL > Mailing List > Monthly Index > Single Mail

curl-tracker mailing list Archives

[ curl-Bugs-2913886 ] proxy and ftp - never issues request

From: SourceForge.net <noreply_at_sourceforge.net>
Date: Mon, 14 Dec 2009 23:17:37 +0000

Bugs item #2913886, was opened at 2009-12-13 23:07
Message generated for change (Comment added) made by bagder
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=2913886&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: wrong behaviour
>Status: Pending
>Resolution: Fixed
Priority: 5
Private: No
Submitted By: Jon Nelson (jnelson)
Assigned to: Daniel Stenberg (bagder)
Summary: proxy and ftp - never issues request

Initial Comment:
curl 7.19.6 on openSUSE 11.2, connecting via ftp through a squid proxy.

I noticed a problem attempting to fetch from an ftp resources that curl appeared to connect and then do nothing until it eventually timed out.
Suspecting some other problem, I tried aria2, wget, and firefox -- all of which worked just fine.

So I strace'd curl and this is what I get (the proxy is 192.168.1.1 port 3128):
...

10137 16:03:52.937144 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3 <0.000020>
10137 16:03:52.937229 setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 <0.000015>
10137 16:03:52.937290 fcntl(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000012>
10137 16:03:52.937340 fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000011>
10137 16:03:52.937394 connect(3, {sa_family=AF_INET, sin_port=htons(3128), sin_addr=inet_addr("192.168.1.1")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000057>
10137 16:03:52.937516 poll([{fd=3, events=POLLOUT}], 1, 299999) = 1 ([{fd=3, revents=POLLOUT}]) <0.000879>
10137 16:03:52.938452 getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000012>
10137 16:03:52.938516 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 3600000) = 1 ([{fd=3, revents=POLLIN}]) <29.348688>
10137 16:04:22.287387 recvfrom(3, "", 16384, 0, NULL, NULL) = 0 <0.000028>
10137 16:04:22.287525 close(3) = 0 <0.000079>

followed by curl grumping (error 56).

What I don't understand is why, after the connect is successful, curl doesn't send the proxy anything.

----------------------------------------------------------------------

>Comment By: Daniel Stenberg (bagder)
Date: 2009-12-15 00:17

Message:
Thanks a lot. I tracked it down, fixed it, added a new test case for this
(1106) and committed the lot just now to CVS (with credit to you for the
discovery and report). Case closed!

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-14 22:28

Message:
Whoa, very nice catch. I believe that may also be why the test cases never
glitched since they all just use -x/--proxy and not the environment
variable approach.

Ok, so I'll just have to figure out how this happens...

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 22:25

Message:
I think we have a winner.
I tried the following, after *unsetting* *all* proxy environment
variables:

curl -x 192.168.1.1:3128 ftp://ftp.suse.com/

and it worked

So did the following variations:

curl -x http://192.168.1.1:3128 ftp://ftp.suse.com/
curl -x http://192.168.1.1:3128/ ftp://ftp.suse.com/

but this did not:

env ftp_proxy=http://192.168.1.1:3128/ curl ftp://ftp.suse.com/
and neither did this:
env ftp_proxy=192.168.1.1:3128 curl ftp://ftp.suse.com/

So it would seem as though the proxy stuff as it comes from the
environment is busted.

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-14 22:18

Message:
I'm using Apache with its proxy_ftp enabled, eglibc 2.10.2, Linux 2.6.31 on
i686 32bit

I invoke curl with

curl -x localhost:80 ftp://ftp.sunet.se/

As long as it picks up the proxy, it really doesn't matter if it's done
with -x or an environment variable.

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 20:22

Message:
What proxy did you go through? I am using squid.

The recv/recvfrom is expected - this is going to vary a bit depending on
what kernel and glibc one is using (if one is using Linux). I am on glibc
2.10.1, kernel 2.6.31.5, x86_64. The working version I have (7.19.4) shows
recvfrom and sendto.

How did you invoke it, exactly? What was the exact commandline and what
proxy environment variables were present? (env | grep -i proxy)

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-14 19:48

Message:
Also, my strace outputs show NO calls to recvfrom() at all. TCP data is
clearly received with recv(). The particular piece from connect() to the
first write() looks like this:

connect(3, {sa_family=AF_INET, sin_port=htons(80),
sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in
progress)
clock_gettime(CLOCK_MONOTONIC, {434720, 492568076}) = 0
poll([{fd=3, events=POLLOUT}], 1, 299997) = 1 ([{fd=3, revents=POLLOUT}])
getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
clock_gettime(CLOCK_MONOTONIC, {434720, 492678711}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
write(2, "connected\n", 10connected
) = 10
clock_gettime(CLOCK_MONOTONIC, {434720, 492808025}) = 0
clock_gettime(CLOCK_MONOTONIC, {434720, 492840544}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
write(2, "*", 1*) = 1
write(2, " ", 1 ) = 1
write(2, "Connected to localhost (127.0.0."..., 48Connected to localhost
(127.0.0.1) port 80 (#0)
) = 48
clock_gettime(CLOCK_MONOTONIC, {434720, 493056415}) = 0
clock_gettime(CLOCK_MONOTONIC, {434720, 493086293}) = 0
clock_gettime(CLOCK_MONOTONIC, {434720, 493115332}) = 0
send(3, "GET ftp://ftp.sunet.se HTTP/1.1\r"..., 215, MSG_NOSIGNAL) = 215
clock_gettime(CLOCK_MONOTONIC, {434720, 493816701}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
write(2, ">", 1>) = 1
write(2, " ", 1 ) = 1
write(2, "GET ftp://ftp.sunet.se HTTP/1.1\r"..., 33GET ftp://ftp.sunet.se
HTTP/1.1
) = 33

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-14 19:41

Message:
Just FYI, I can do ftp over proxy just fine. I just tested 7.19.7 and my
dev 7.20.0 version over a locally installed proxy. It's clearly not as
simple as working vs not working. This also explains why all test cases
still run fine: there's a subtle difference somewhere...

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 17:58

Message:
I tried 7.19.5 and 7.19.4.
7.19.5 did *not* work, 7.19.4, however, works fine.
Somewhere between 7.19.4 and 7.19.5....

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 17:14

Message:
7.19.7 does not fix for me.
I'll work backwards in versions.

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-14 16:21

Message:
Any chance you can just run a quick test with 7.19.7 too, just to make sure
it still shows the same badness?

In my end I'll work on getting some actual proxy up that proxies ftp like
this so I can make some tests.

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 16:15

Message:
One thing to note: I tried an older version (curl 7.19.0) on openSUSE 11.1
and it works just fine in exactly the same scenario.

The strace looks fine, too:

connect followed by poll, getsockopt, sendto (this part is missing above),
a few more polls and then it begins receiving the data.

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-14 00:14

Message:
recv frequently gets turned into recvfrom by the C library.

Look at the timestamps. The recv[from] returning 0 is perfectly
reasonable: the proxy accepted a request, waited 30 seconds, never got a
request, and closed the connection.

The core of the problem is still this: curl isn't ever asking the proxy
for anything. it connects, and then waits for a response. it won't get one.
ever. it's not asked for anything.

I'm invoking curl like this:

curl --trace-ascii - --trace-time
ftp://ftp.suse.com/pub/projects/kernel/kotd/openSUSE-11.2/x86_64/kernel-desktop-base-2.6.31.7-0.0.0.8.a22d080.x86_64.rpm

the environment looks like this:

frank:~ # env | grep -i prox
http_proxy=http://192.168.1.1:3128/
ftp_proxy=http://192.168.1.1:3128/
https_proxy=http://192.168.1.1:3128/
frank:~ #

remember: wget works perfectly in the same environment. so does aria2.

wget is doing what one would expect:
connect to the proxy
write a request.
read response

Here is the wget strace:

socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3128),
sin_addr=inet_addr("192.168.1.1")}, 16) = 0
write(2, "connected.\n", 11) = 11
select(4, NULL, [3], NULL, {900, 0}) = 1 (out [3], left {899, 999996})
write(3, "GET ftp://ftp.suse.com/pub/proje"..., 195) = 195
write(2, "Proxy request sent, awaiting res"..., 41) = 41
....

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-13 23:47

Message:
I disagree with your conclusion.

First, I assume that libcurl's use of recv() somehow gets translated into
a recvfrom() (which in my book is strange in itself but lets ignore that
for now). But if that recvfrom() returns 0 after having poll() told the
socket is readable, that's an end of the connection. Let me quote the man
page: "The return value will be 0 when the peer has performed an orderly
shutdown.". So the question is then why the other end end closes down the
connection that fast.

Second, what makes me very curious is the comment "FTP response reading
failed" (a "normal" ftp over HTTP proxy does no such thing as it no longer
does FTP then but is doing HTTP and then it never waits for FTP responses).
Are you by any chance doing "tunneling" through the proxy? Can you show us
a full command line that you use when you experience these problems.

----------------------------------------------------------------------

Comment By: Jon Nelson (jnelson)
Date: 2009-12-13 23:40

Message:
The recvfrom:
10137 16:04:22.287387 recvfrom(3, "", 16384, 0, NULL, NULL) = 0 <0.000028>

is receiving from file descriptor no 3. fd 3 was created here:

10137 16:03:52.937144 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
<0.000020>

(clearly a TCP socket) and the subsequent statements clearly show it to be
the socket which curl is using to communicate with the proxy:

10137 16:03:52.937394 connect(3, {sa_family=AF_INET,
sin_port=htons(3128),
sin_addr=inet_addr("192.168.1.1")}, 16) = -1 EINPROGRESS (Operation now
in
progress) <0.000057>

--trace-ascii and --trace-time added:

18:21:57.436169 == Info: About to connect() to proxy 192.168.1.1 port 3128
(#0)
18:21:57.437620 == Info: Trying 192.168.1.1... 18:21:57.439207 == Info:
connected
18:21:57.439770 == Info: Connected to 192.168.1.1 (192.168.1.1) port 3128
(#0)

18:22:26.845603 == Info: FTP response reading failed
18:22:26.845939 == Info: Closing connection #0
curl: (56) FTP response reading failed

The strace is pretty clear to me that curl (or libcurl) is simply waiting
for a response that will never come. The response will never come because
it never asks for anything!

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2009-12-13 23:31

Message:
recvfrom() ?? Is that from the DNS resolve? It doesnät make sense to me.

Can you run curl with --trace-ascii and get a dump of that to show us?

We run ftp over http proxy in our test suite (in several test cases even),
which runs fine on every release before we ship it and it still runs fine
in our current dev version.

----------------------------------------------------------------------

You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=2913886&group_id=976
Received on 2009-12-15

These mail archives are generated by hypermail.

donate! Page updated November 12, 2010.
web site info

File upload with ASP.NET