Comment 1 for bug 172701

Revision history for this message
Vincent Ladeuil (vila) wrote : Re: [Bug 172701] Large readv requests can fail if there is a squid proxy

>>>>> "Andrew" == Andrew Bennetts <email address hidden> writes:

    Andrew> Public bug reported:
    Andrew> I have a bzr branch at 2977
    Andrew> <email address hidden> in packs-0.92 format.

    Andrew> I have a checkout (in a separate repository) of current bzr.dev (3041
    Andrew> <email address hidden>)

    Andrew> When using current bzr.dev to update the 2977 branch from http://bazaar-
    Andrew> vcs.org/bzr/bzr.dev/ I got this error:

    Andrew> ShortReadvError: readv() read unknown bytes rather than unknown bytes at
    Andrew> unknown for "http://bazaar-
    Andrew> vcs.org/bzr/bzr.dev/.bzr/repository/packs/a3069b4df97462558e8666ff0cc72386.pack":
    Andrew> Server aborted the request

    Andrew> Also, it took 38m32s wall time!

Ouch.

    Andrew> This is repeatable. (It's slightly exacerbated by the fact that bzr is
    Andrew> uninterruptible by Ctrl-C or Ctrl-\ during this, apparently due to being
    Andrew> inside pycurl; I think there's already a bug about that).

I don't remember a bug about this, but even, we can hardly fix
it, the workaround is to use urllib instead.

    Andrew> At Robert's suggestion, I bypassed my home network's squid proxy. This
    Andrew> avoids the problem; the pull succeeds in slightly over 3 minutes.

Robert, what made you think about that work-around ?

    Andrew> Here is the full .bzr.log contents for this invocation:

    Andrew> bzr arguments: [u'pull']
    Andrew> looking for plugins in /home/andrew/.bazaar/plugins
    Andrew> looking for plugins in /tmp/bzr.packs/bzrlib/plugins
    Andrew> Plugin name __init__ already loaded
    Andrew> Plugin name __init__ already loaded
    Andrew> encoding stdout as sys.stdout encoding 'UTF-8'
    Andrew> opening working tree '/home/andrew/code/bzr'
    Andrew> Using fetch logic to copy between KnitPackRepository('http://bazaar-vcs.org/bzr/bzr.dev/.bzr/repository/')(<RepositoryFormatKnitPack1>) and KnitPackRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/')(<RepositoryFormatKnitPack1>)

<snip/>
    Andrew> http readv of a3069b4df97462558e8666ff0cc72386.pack offsets => 649 collapsed 149
    Andrew> got pycurl error: 18, transfer closed with 162685 bytes remaining to read, (18, 'transfer closed with 162685 bytes remaining to read'), url: http://bazaar-vcs.org/bzr/bzr.dev/.bzr/repository/packs/a3069b4df97462558e8666ff0cc72386.pack

This is pycurl detecting a short read, to say the truth I never
encountered it myself, the code was ready for it though. packs
are really making life hard for our http implementations ;-)

Did your squid logs shed some light on why it occurred ?
Apparently the 169 ranges request was accepted so I wonder why it
decided to interrupt the transfer of the body part...

Anyway, that confirmed just what I was afraid of, it means readv
has to keep track of which offsets have been already transferred
to avoid requesting them again.

<snip/>

    Andrew> File "/tmp/bzr.packs/bzrlib/transport/http/_pycurl.py", line 304, in _curl_perform
    Andrew> extra='Server aborted the request')
    Andrew> ShortReadvError: readv() read unknown bytes rather than unknown bytes at unknown for "http://bazaar-vcs.org/bzr/bzr.dev/.bzr/repository/packs/a3069b4df97462558e8666ff0cc72386.pack": Server aborted the request

And unfortunately pycurl do not tell us where we failed.

For that, can you retry with pycurl but with line

     curl.setopt(pycurl.VERBOSE, 1)

uncommented out (in _pycurl.py around line 267) ?

That will display the headers sent and received and help understanding what happened.