git clone http:// fails some times with "Request for d53.. aborted"

even when (v 2.7.0) ran on the box where the server is, so unlikely to be network issue

or from my laptop (v 2.9.3) with ok but wifi with a weakish signal to the access point:

$> ( set -e; for s in {1..100}; do rm -rf fbirn_phaseIII ; git clone http://datasets.datalad.org/nidm/fbirn_phaseIII/.git; done; ) Cloning into 'fbirn_phaseIII'... Checking connectivity... done. Cloning into 'fbirn_phaseIII'... error: Request for d53302dfc7ad13b786923927021039d21a10d5bd aborted error: Unable to find d53302dfc7ad13b786923927021039d21a10d5bd under http://datasets.datalad.org/nidm/fbirn_phaseIII/.git Cannot obtain needed tree d53302dfc7ad13b786923927021039d21a10d5bd while processing commit 22dd4c49417cad6f4082ac2aebef45da8b6e473d. error: fetch failed.

even if I build fresh 2.10.0, discovered that we can trace now CURL calls

$> export PATH=$HOME/proj/misc/git:$PATH $> git version git version 2.10.0 $> ( set -e; for s in {1..100}; do rm -rf fbirn_phaseIII ; GIT_TRACE_CURL=/tmp/git-trace-curl-failed.log git clone http://datasets.datalad.org/nidm/fbirn_phaseIII/.git && mv /tmp/git-trace-curl-failed.log /tmp/git-trace-curl-good.log || exit 1; done; ) Cloning into 'fbirn_phaseIII'... warning: templates not found /home/yoh/share/git-core/templates ... a few more ... Cloning into 'fbirn_phaseIII'... warning: templates not found /home/yoh/share/git-core/templates error: Request for d53302dfc7ad13b786923927021039d21a10d5bd aborted error: Unable to find d53302dfc7ad13b786923927021039d21a10d5bd under http://datasets.datalad.org/nidm/fbirn_phaseIII/.git Cannot obtain needed tree d53302dfc7ad13b786923927021039d21a10d5bd while processing commit 22dd4c49417cad6f4082ac2aebef45da8b6e473d. error: fetch failed. ( set -e; for s in {1..100}; do; rm -rf fbirn_phaseIII; GIT_TRACE_CURL= git ) 18.70s user 8.01s system 34% cpu 1:16.84 total

NB 
- note that it is d53302dfc7ad13b786923927021039d21a10d5bd all the time!
- that one corresponds to a tree
$> git show d53302dfc7ad13b786923927021039d21a10d5bd
tree d53302dfc7ad13b786923927021039d21a10d5bd

1ec/
da9/
- I do not see that object being reported as failed to be found on the server:

$> grep d5/3302dfc7ad13b786923927021039d21a10d5bd /var/log/apache2/datasets.datalad.org-error.log
$> grep d5/3302dfc7ad13b786923927021039d21a10d5bd /var/log/apache2/datasets.datalad.org-access.log
129.170.31.34 - - [09/Sep/2016:14:14:25 -0400] "GET /nidm/fbirn_phaseIII/.git/objects/d5/3302dfc7ad13b786923927021039d21a10d5bd HTTP/1.1" 200 72
...
- and the logs say that only "good" run had it requested:

$> zgrep 3302dfc7ad13b786923927021039d21a10d5bd git-trace-curl-*.log.gz git-trace-curl-good.log.gz:18:09:13.749268 http.c:517 => Send header: GET /nidm/fbirn_phaseIII/.git/objects/d5/3302dfc7ad13b786923927021039d21a10d5bd HTTP/1.1

and here are those two GIT_TRACE_CURL traces from good and bad runs -- may be someone with a better clue could figure it out or any other information I should provide to help pin point why that "request for d5... aborted" ;)

http://www.onerussian.com/tmp/git-trace-curl-good.log.gz http://www.onerussian.com/tmp/git-trace-curl-failed.log.gz

Thanks in advance and please CC me in replies

(Not sure how much time I'll have to continue in the next few weeks,
 just jotting down my debugging progress so far...)

Yaroslav Halchenko <yoh@onerussian.com> wrote:

Also, GIT_CURL_VERBOSE=1 is useful, too

And GIT_HTTP_MAX_REQUESTS=1 (default 5) can be used to limit concurrency if there's a suspected concurrency bug.

Initially, I was worried some of my 2.10.0 http-walker speedups were responsible, but it does not seem to be the case since it happens on old versions, too...

I'm trying with the following to track state==ABORTED requests:

(I have some hours online today, so I decided to work on this)

The key patch here is 3/3 which seems like an obvious fix to adding the problem of adding a curl easy handle to a curl multi handle repeatedly.

What is unclear to me is how only Yaroslav's repository seems to trigger this bug after all these years...

However, I am fairly sure this fixes the bug Yaroslav encountered. This patch series is also needed for 2.9.3 and perhaps older maintenance tracks for distros.

In PATCH 2/3, I originally had error checking, but removed it after noticing it was causing failures on wheezy.

I will investigate those failures in a week or two when I regain regular computer access.

These patches are needed for 2.9.x (and probably earlier), too.

The following changes since commit cda1bbd474805e653dda8a71d4ea3790e2a66cbb:

  Sync with maint (2016-09-08 22:00:53 -0700)

are available in the git repository at:

  git://bogomips.org/git-svn.git dumb-http-release

for you to fetch changes up to 3f561d0f0f78fd841708b5e81122e9d825919fd3:

  http: always remove curl easy from curlm session on release (2016-09-12 23:59:35 +0000)

----------------------------------------------------------------
Eric Wong (3):
  http: warn on curl_multi_add_handle failures
  http: consolidate #ifdefs for curl_multi_remove_handle
  http: always remove curl easy from curlm session on release

 http.c | 29 ++++++++++++++++++-----------
 1 file changed, 18 insertions(+), 11 deletions(-)

This will be useful for tracking down curl usage errors.

Signed-off-by: Eric Wong <e@80x24.org>
---
 http.c | 2 ++
 1 file changed, 2 insertions(+)

I find #ifdefs makes code difficult-to-follow.

An early version of this patch had error checking for curl_multi_remove_handle calls, but caused some tests (e.g. t5541) to fail under curl 7.26.0 on old Debian wheezy.

Signed-off-by: Eric Wong <e@80x24.org>
---
 http.c | 17 ++++++++++-------
 1 file changed, 10 insertions(+), 7 deletions(-)

We must call curl_multi_remove_handle when releasing the slot to prevent subsequent calls to curl_multi_add_handle from failing with CURLM_ADDED_ALREADY (in curl 7.32.1+; older versions returned CURLM_BAD_EASY_HANDLE)

Signed-off-by: Eric Wong <e@80x24.org>
---
 http.c | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

Eric Wong <e@80x24.org> writes:

Yeah, sounds like the right thing to do and 2/3 makes it really easy to read the resulting code.

Thanks. Will tentatively queue on 'pu' and wait for updates.

Junio C Hamano <gitster@pobox.com> wrote:

I'm comfortable with the original 3 patch series in 'next' and being merged to 'master' and 'maint', soon.

I don't think the following 4/3 is strictly necessary now, so I'd be more comfortable with it being tested in 'pu' or 'next' for a longer period.

(online today, but not much tomorrow or another few days after)

-----------8<-----------
Subject: [PATCH] http: check curl_multi_remove_handle error code

This should help detect bugs in future changes. While we're at it, fix a (probably innocuous) bug in our http_cleanup function for users of older curl.

curl_multi_remove_handle was not idempotent until curl 7.33.0 with commit 84f3b3dd448399f9548468676e1bd1475dba8de5 ("curl_multi_remove_handle: allow multiple removes"), so we track the "curlm" membership of the curl easy handle ourselves with a new "in_multi" flag.

Tested with curl 7.26.0 and 7.38.0 on Debian 7.x (wheezy) and Debian 8.x (jessie) respectively.

Signed-off-by: Eric Wong <e@80x24.org>
---
 http.c | 12 ++++++++++--
 http.h |  1 +
 2 files changed, 11 insertions(+), 2 deletions(-)

On Wed, Sep 21, 2016 at 09:46:23PM +0000, Eric Wong wrote:

Does curl provide a meaningful error here? I'm just wondering if we could simply let curl handle this, and just ignore the error that comes from older versions. We're basically just replicating curl's own state data here.

-Peff

Jeff King <peff@peff.net> wrote:

curl before 7.33.0 returned CURLM_BAD_EASY_HANDLE. This error code also happens if we pass a bad/corrupt easy handle; so it could be hiding an error on our end.

On Wed, Sep 21, 2016 at 10:29:59PM +0000, Eric Wong wrote:

Hmm, yeah. So we would want to make it conditional on the version anyway, so that we detected such bugs on more modern systems. That still doesn't seem unreasonable to me, but your patch is also not very big, so it's probably fine (the major risk with yours is simply that our state and curl's state get out of sync).

-Peff

On Tue, 13 Sep 2016, Eric Wong wrote:

Thank you Eric very much for tracking down this issue! Since issue is intermittent, I guess people just didn't bother going through reporting if they got an error once in a while, and/or could have attributed to somehow misran update-server-info.

FWIW I have tested your branch locally - and do not observe that bug any longer. Thanks again!

I have spent some time chasing the wild goose (well - the .gitignore file) after getting:

    $> git-submodule add --name fcx-1 ./fcx-1/ ./fcx-1/
    The following path is ignored by one of your .gitignore files:
    fcx-1
    Use -f if you really want to add it.

long story short -- the culprit is this piece of code in git-submodule:

    if test -z "$force" && ! git add --dry-run --ignore-missing "$sm_path" > /dev/null 2>&1
    then
        eval_gettextln "The following path is ignored by one of your .gitignore files:
\$sm_path
Use -f if you really want to add it." >&2
        exit 1
    fi

so if anything goes wrong in git add, it just reports this error message.

FTR -- actual problem in my case was:

    $> git add --dry-run --ignore-missing fcx-1
    fatal: Unable to create '/mnt/datasets/datalad/crawl/crcns/.git/index.lock': File exists.

    Another git process seems to be running in this repository, e.g.
    an editor opened by 'git commit'. Please make sure all processes
    are terminated then try again. If it still fails, a git process
    may have crashed in this repository earlier:
    remove the file manually to continue.

;-)

Cheers! P.S. Please CC me in replies

On Wed, Sep 14, 2016 at 7:03 AM, Yaroslav Halchenko <yoh@onerussian.com> wrote:

Thanks for the bug report! I think we could chop off "2>&1" as that would have exposed the underlying error.

Another way to go would be to use verbose git-add and grep for the string "add '$sm_path'".

     if test -z "$force" && ! git add --verbose --dry-run
--ignore-missing "$sm_path" |grep "add $sm_path"

git-add already gives the correct (the same error message) for the ignored files, so maybe we'd just do:

    # no need for a if, but this single line will do:
    test -z "$force" && git add --dry-run git.o >/dev/null || exit 1

On September 14, 2016 3:32:11 PM EDT, Stefan Beller <sbeller@google.com> wrote: !

FWIW Imho exposing error is good but not sufficient alone, since custom gitignore message would still be confusing.