Skip to contentSkip to conversation

master: t5800-remote-helpers.sh hangs on test "pulling from remote remote"

PATCH In review Stefano Lattarini 6 participants 26 messages Jun 15, 2016 1 message not in the archive

lore
Share & tools
lore
#0 lore raw

The test 't5800-remote-helpers.sh' hangs on my Linux desktop (where I have installed a custom simple-minded firewall based on iptables). This does not happen on remote systems I use for testing, so I guess the problem lies with my machine. Still, having the test to hang is unnecessarily harsh and user-unfriendly IMHO, and it would be better to detect the situation and SKIP or FAIL the affected test cases instead.

For reference, here is the output of the test 't5800-remote-helpers.sh' run with the '-v' option:

-*-*-

Initialized empty Git repository in /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/.git/ expecting success:

        git init --bare server/.git &&
        git clone server public &&
        (cd public &&
         echo content >file &&
         git add file &&
         git commit -m one &&
         git push origin master)

Initialized empty Git repository in /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git/ Cloning into 'public'...
warning: You appear to have cloned an empty repository.
done.
[master (root-commit) 9a7aa46] one
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)
 create mode 100644 file

Counting objects: 3, done.
Unpacking objects: 100% (3/3), done.
Writing objects: 100% (3/3), 219 bytes, done.
Total 3 (delta 0), reused 0 (delta 0)
To /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server
* [new branch] master -> master
ok 1 - setup repository

expecting success:
git clone "testgit::${PWD}/server" localclone && test_cmp public/file localclone/file

Cloning into 'localclone'...
ok 2 - cloning from local repo

expecting success:
git clone "testgit::file://${PWD}/server" clone && test_cmp public/file clone/file

Cloning into 'clone'...
ok 3 - cloning from remote repo

expecting success:

        (cd public &&
         echo content >>file &&
         git commit -a -m two &&
         git push)

[master 0eb255a] two
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)

Counting objects: 5, done.
Unpacking objects: 100% (3/3), done.
Writing objects: 100% (3/3), 252 bytes, done.
Total 3 (delta 0), reused 0 (delta 0)
To /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server
9a7aa46..0eb255a master -> master
ok 4 - create new commit on remote

expecting success:
(cd localclone && git pull) &&
test_cmp public/file localclone/file

Quoted 1 line

From testgit::/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server

9a7aa46..0eb255a master -> origin/master
Updating 9a7aa46..0eb255a
Fast-forward

 file |    1 +
 1 file changed, 1 insertion(+)

ok 5 - pulling from local repo

expecting success:
(cd clone && git pull) &&
test_cmp public/file clone/file

Quoted 1 line

From testgit::file:///devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server

9a7aa46..0eb255a master -> origin/master
Updating 9a7aa46..0eb255a
Fast-forward

 file |    1 +
 1 file changed, 1 insertion(+)

ok 6 - pulling from remote remote

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        git push) &&
        compare_refs localclone HEAD server HEAD

[master 30d4cae] three
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)

-*-*-

At this point, the test hangs, and I have to manually kill it with a SIGINT, the result being:

-*-*-

Traceback (most recent call last):
File "/devel/stefano/src/git/git-remote-testgit", line 265, in <module>
sys.exit(main(sys.argv))
File "/devel/stefano/src/git/git-remote-testgit", line 262, in main
more = read_one_line(repo)
File "/devel/stefano/src/git/git-remote-testgit", line 227, in read_one_line
func(repo, cmdline)
File "/devel/stefano/src/git/git-remote-testgit", line 175, in do_export
changed = repo.importer.do_import(repo.gitdir)
File "/home/stefano/src/git/t/../git_remote_helpers/build/lib/git_remote_helpers/git/importer.py", line 54, in do_import
check_call(args)
File "/home/stefano/src/git/t/../git_remote_helpers/build/lib/git_remote_helpers/util.py", line 169, in check_call
retcode = call(*popenargs, **kwargs)
File "/home/stefano/src/git/t/../git_remote_helpers/build/lib/git_remote_helpers/util.py", line 155, in call
return subprocess.Popen(*popenargs, **kwargs).wait()
File "/usr/lib/python2.7/subprocess.py", line 1291, in wait
pid, sts = _eintr_retry_call(os.waitpid, self.pid, 0)
File "/usr/lib/python2.7/subprocess.py", line 478, in _eintr_retry_call
return func(*args)
KeyboardInterrupt
FATAL: Unexpected exit with code 0

-*-*-

If I run ps(1) in another terminal before interrupting the hung test, the following command sticks out as a possible culprit:

git-fast-import --quiet --export-marks=/devel/stefano/src/git/t/trash \
directory.t5800-remote-helpers/localclone/.git/info/fast-import/\
c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks \
--import-marks=/devel/stefano/src/git/t/'trash directory.t5800-remote-helpers'/\
localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/\
git.marks

-*-*-

Other possibly relevant information:

  $ hg --version | head -1
  Mercurial Distributed SCM (version 1.8.3) $ python --version
  $ python --version
  Python 2.7.2+
  $ /bin/sh --version | head -1
  GNU bash, version 4.1.5(1)-release (i486-pc-linux-gnu)
  $ git describe
  v1.7.10-167-gf245c01
#1 lore raw
Quoted 5 lines · Stefano Lattarini

The test 't5800-remote-helpers.sh' hangs on my Linux desktop (where I have installed a custom simple-minded firewall based on iptables). This does not happen on remote systems I use for testing, so I guess the problem lies with my machine.

I don't think this particular test is related to networking. Could you please run the test again with the following change and paste the output? (You cannot set the variables on the command line, because test-lib.sh would unset them.)

t/t5800-remote-helpers.sh +1 -1
index 1c62001..4cebd63 100755
@@ -68,7 +68,7 @@ test_expect_success 'pushing to local repo' '
 	(cd localclone &&
 	echo content >>file &&
 	git commit -a -m three &&
-	git push) &&
+	GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
 	compare_refs localclone HEAD server HEAD
 '
 
#2 lore raw
Quoted 17 lines · Clemens Buchacher
Quoted 5 lines · Stefano Lattarini

The test 't5800-remote-helpers.sh' hangs on my Linux desktop (where I have installed a custom simple-minded firewall based on iptables). This does not happen on remote systems I use for testing, so I guess the problem lies with my machine.

I don't think this particular test is related to networking. Could you please run the test again with the following change and paste the output? (You cannot set the variables on the command line, because test-lib.sh would unset them.)

t/t5800-remote-helpers.sh +0 -0
index 1c62001..4cebd63 100755

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 74

Quoted 8 lines
t/t5800-remote-helpers.sh +1 -1
@@ -68,7 +68,7 @@ test_expect_success 'pushing to local repo' '
 	(cd localclone &&
 	echo content >>file &&
 	git commit -a -m three &&
-	git push) &&
+	GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
 	compare_refs localclone HEAD server HEAD
 '
 

Here it goes:

-*-*-

$ ./t5800-remote-helpers.sh -v

Initialized empty Git repository in /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/.git/ expecting success:

        git init --bare server/.git &&
        git clone server public &&
        (cd public &&
         echo content >file &&
         git add file &&
         git commit -m one &&
         git push origin master)

Initialized empty Git repository in /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git/ Cloning into 'public'...
warning: You appear to have cloned an empty repository.
done.
[master (root-commit) c1c95c0] one
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)
 create mode 100644 file

Counting objects: 3, done.
Unpacking objects: 100% (3/3), done.
Writing objects: 100% (3/3), 219 bytes, done.
Total 3 (delta 0), reused 0 (delta 0)
To /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server
* [new branch] master -> master
ok 1 - setup repository

expecting success:
git clone "testgit::${PWD}/server" localclone && test_cmp public/file localclone/file

Cloning into 'localclone'...
ok 2 - cloning from local repo

expecting success:
git clone "testgit::file://${PWD}/server" clone && test_cmp public/file clone/file

Cloning into 'clone'...
ok 3 - cloning from remote repo

expecting success:

        (cd public &&
         echo content >>file &&
         git commit -a -m two &&
         git push)

[master df9eab7] two
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)

Counting objects: 5, done.
Unpacking objects: 100% (3/3), done.
Writing objects: 100% (3/3), 250 bytes, done.
Total 3 (delta 0), reused 0 (delta 0)
To /devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server
c1c95c0..df9eab7 master -> master
ok 4 - create new commit on remote

expecting success:
(cd localclone && git pull) &&
test_cmp public/file localclone/file

Quoted 1 line

From testgit::/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server

c1c95c0..df9eab7 master -> origin/master
Updating c1c95c0..df9eab7
Fast-forward

 file |    1 +
 1 file changed, 1 insertion(+)

ok 5 - pulling from local repo

expecting success:
(cd clone && git pull) &&
test_cmp public/file clone/file

Quoted 1 line

From testgit::file:///devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server

c1c95c0..df9eab7 master -> origin/master
Updating c1c95c0..df9eab7
Fast-forward

 file |    1 +
 1 file changed, 1 insertion(+)

ok 6 - pulling from remote remote

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD

[master 4dcddca] three
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)

Debug: Remote helper: -> capabilities
Debug: Remote helper: Waiting...
prefix: 'refs/testgit/origin/'
Got arguments ['origin', '/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server'] Got command 'capabilities' with args ''
Debug: Remote helper: <- import
Debug: Got cap import
Debug: Remote helper: Waiting...
Debug: Remote helper: <- export
Debug: Got cap export
Debug: Remote helper: Waiting...
Debug: Remote helper: <- refspec refs/heads/*:refs/testgit/origin/*
Debug: Got cap refspec refs/heads/*:refs/testgit/origin/*
Debug: Remote helper: Waiting...
Debug: Remote helper: <- *export-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Got cap export-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Remote helper: Waiting...
Debug: Remote helper: <- *import-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Got cap import-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Remote helper: Waiting...
Debug: Remote helper: <-
Debug: Capabilities complete.
Debug: Remote helper: Waiting...
Got command 'list' with args ''
? refs/heads/master
@refs/heads/master HEAD
Debug: Remote helper: <- ? refs/heads/master
Debug: Remote helper: Waiting...
Debug: Remote helper: <- @refs/heads/master HEAD
Debug: Remote helper: Waiting...
Debug: Remote helper: <-
Debug: Read ref listing.
Debug: Remote helper: -> export
Got command 'export' with args ''
Debug: Remote helper: Waiting...

-*-*-

The test hangs at this point.

Thanks,
Stefano

#3 lore raw
Quoted 4 lines · Stefano Lattarini

Debug: Remote helper: -> export
Got command 'export' with args ''
Debug: Remote helper: Waiting...

Hmm. Looks like fast-import and fast-export are in a deadlock. It's probably time to let the experts take over. But if you want to indulge me further, you could try again with GIT_TRACE=1. That should give you the arguments to use for the fast-export and fast-import commands right before it hangs. Then run ./t5800-remote-helpers.sh -i with the following change to make it abort right before git push:

t/t5800-remote-helpers.sh +2 -1
index 1c62001..c4855e9 100755
@@ -68,7 +68,8 @@ test_expect_success 'pushing to local repo' '
        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
-       git push) &&
+       false &&
+       GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD
 '
 

You can manually now run fast-export using the arguments from the first run, for example in my case:

cd trash\ directory.t5800-remote-helpers
(cd localclone; git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '--import-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master') |

That should output:

feature done
blob
mark :5
data 24
content
content
content

commit refs/heads/master
mark :6
author A U Thor <[email protected]> 1334451823 +0000 committer C O Mitter <[email protected]> 1334451823 +0000 data 6
three
from :4
M 100644 :5 file

done

Finally, you can manually pipe fast-export to fast-import, again using the arguments from the first run:

cd trash\ directory.t5800-remote-helpers
(cd localclone; git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '--import-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master') |
(cd server; git fast-import '--quiet' '--export-marks=/home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks' '--import-marks=/home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks')

If the fast-export output is the same, and if the last command also hangs for you, then we can start debugging fast-import.

Clemens

#4 lore raw
Quoted 4 lines · Clemens Buchacher

But if you want to indulge
me further, you could try again with GIT_TRACE=1. That should give you the arguments to use for the fast-export and fast-import commands right before it hangs.

Here is the output:

-*-*-

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD

[master 813bd24] three
Author: A U Thor <[email protected]>

 1 file changed, 1 insertion(+)

trace: built-in: git 'push'
trace: run_command: 'git-remote-testgit' 'origin' '/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server'
Debug: Remote helper: -> capabilities
Debug: Remote helper: Waiting...
trace: built-in: git 'ls-remote' '/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git'
trace: run_command: 'git-upload-pack '\''/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git'\'''
trace: exec: 'sh' '-c' 'git-upload-pack '\''/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git'\''' 'git-upload-pack '\''/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server/.git'\'''
prefix: 'refs/testgit/origin/'
Got arguments ['origin', '/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/server']
Got command 'capabilities' with args ''
Debug: Remote helper: <- import
Debug: Got cap import
Debug: Remote helper: Waiting...
Debug: Remote helper: <- export
Debug: Got cap export
Debug: Remote helper: Waiting...
Debug: Remote helper: <- refspec refs/heads/*:refs/testgit/origin/*
Debug: Got cap refspec refs/heads/*:refs/testgit/origin/*
Debug: Remote helper: Waiting...
Debug: Remote helper: <- *export-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Got cap export-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Remote helper: Waiting...
Debug: Remote helper: <- *import-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Got cap import-marks .git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks
Debug: Remote helper: Waiting...
Debug: Remote helper: <-
Debug: Capabilities complete.
Debug: Remote helper: Waiting...
Got command 'list' with args ''
? refs/heads/master
@refs/heads/master HEAD
Debug: Remote helper: <- ? refs/heads/master
Debug: Remote helper: Waiting...
Debug: Remote helper: <- @refs/heads/master HEAD
Debug: Remote helper: Waiting...
Debug: Remote helper: <-
Debug: Read ref listing.
Debug: Remote helper: -> export
trace: run_command: 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
trace: exec: 'git' 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
trace: built-in: git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
Got command 'export' with args ''
trace: built-in: git 'for-each-ref' 'refs/heads'
Debug: Remote helper: Waiting...
trace: exec: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'
trace: run_command: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

-*-*-

Quoted 2 lines

Then run ./t5800-remote-helpers.sh -i with the following change to make it abort right before git push

With this, the I get:

ok 1 - setup repository
ok 2 - cloning from local repo
ok 3 - cloning from remote repo
ok 4 - create new commit on remote
ok 5 - pulling from local repo
ok 6 - pulling from remote remote
not ok - 7 pushing to local repo
#

  #               (cd localclone &&
  #               echo content >>file &&
  #               git commit -a -m three &&
  #               false &&
  #               GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
  #               compare_refs localclone HEAD server HEAD

#

Thanks,
Stefano

#5 lore raw
Quoted 4 lines · Stefano Lattarini

trace: run_command: 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'

trace: run_command: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

Ok, so the above two commands seem to be deadlocking for you. Could you please run git fast-export with the arguments above from the directory t/trash directory.t5800-remote-helpers/server and check the output? In my previous email I also gave further instructions on how to pipe fast-export output to fast-import. Maybe you missed it, or is anything unclear?

#6 lore raw
Quoted 4 lines · Clemens Buchacher
Quoted 3 lines · Stefano Lattarini

trace: run_command: 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'

Quoted 8 lines
Quoted 1 line

trace: run_command: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

Ok, so the above two commands seem to be deadlocking for you. Could you please run git fast-export with the arguments above from the directory t/trash directory.t5800-remote-helpers/server and check the output?

From the 'localclone' subdirectory:

$ git 'fast-export' '--use-done-feature' \
  '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
  '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
  '^refs/testgit/origin/master' 'refs/heads/master')

feature done
blob
mark :5
data 24
content
content
content

commit refs/heads/master
mark :6
author A U Thor <[email protected]> 1334477289 +0000 committer C O Mitter <[email protected]> 1334477289 +0000 data 6
three
from :4
M 100644 :5 file

done

$ git 'fast-export' '--use-done-feature' \
      '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '^refs/testgit/origin/master' 'refs/heads/master' \
   | git 'fast-import' \
         '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

git-fast-import statistics:
---------------------------------------------------------------------
Alloc'd objects: 5000

  Total objects:            0 (         0 duplicates                  )
        blobs  :            0 (         0 duplicates          0 deltas of          0 attempts)
        trees  :            0 (         0 duplicates          0 deltas of          0 attempts)
        commits:            0 (         0 duplicates          0 deltas of          0 attempts)
        tags   :            0 (         0 duplicates          0 deltas of          0 attempts)
  Total branches:           0 (         0 loads     )
        marks:           1024 (         4 unique    )
        atoms:              0
  Memory total:          2243 KiB
         pools:          2048 KiB
       objects:           195 KiB
  ---------------------------------------------------------------------
  pack_report: getpagesize()            =       4096
  pack_report: core.packedGitWindowSize =   33554432
  pack_report: core.packedGitLimit      =  268435456
  pack_report: pack_used_ctr            =          4
  pack_report: pack_mmap_calls          =          2
  pack_report: pack_open_windows        =          2 /          2
  pack_report: pack_mapped              =        471 /        471

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

Both the commands are successful.

Thanks,
Stefano

#7 lore raw

Hi Stefano,

Almost there. :-)

Quoted 8 lines · Stefano Lattarini
$ git 'fast-export' '--use-done-feature' \
      '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '^refs/testgit/origin/master' 'refs/heads/master' \
   | git 'fast-import' \
         '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

To simulate a git push, you have to run fast-export from localclone and fast-import from the server directory. I.e. starting out in t/trash directory.t5800-remote-helpers:

$ (cd localclone; git fast-export --use-done-feature \
      --export-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      --import-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      ^refs/testgit/origin/master refs/heads/master) |
  (cd server; git fast-import \
         --export-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         --import-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks')
#8 lore raw
Quoted 18 lines · Clemens Buchacher

Hi Stefano,

Almost there. :-)

Quoted 8 lines · Stefano Lattarini
$ git 'fast-export' '--use-done-feature' \
      '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '^refs/testgit/origin/master' 'refs/heads/master' \
   | git 'fast-import' \
         '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

To simulate a git push, you have to run fast-export from localclone and fast-import from the server directory. I.e. starting out in t/trash directory.t5800-remote-helpers:

Quoted 8 lines
$ (cd localclone; git fast-export --use-done-feature \
      --export-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      --import-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      ^refs/testgit/origin/master refs/heads/master) |
  (cd server; git fast-import \
         --export-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         --import-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks')

OK, I cut & pasted your command; it ran successfully, with this output:

git-fast-import statistics:
---------------------------------------------------------------------
Alloc'd objects: 5000

Total objects:            3 (         0 duplicates                  )
      blobs  :            1 (         0 duplicates          0 deltas of          1 attempts)
      trees  :            1 (         0 duplicates          0 deltas of          1 attempts)
      commits:            1 (         0 duplicates          0 deltas of          0 attempts)
      tags   :            0 (         0 duplicates          0 deltas of          0 attempts)
Total branches:           1 (         1 loads     )
      marks:           1024 (         6 unique    )

atoms: 1
Memory total: 2294 KiB
pools: 2098 KiB
objects: 195 KiB
---------------------------------------------------------------------
pack_report: getpagesize() = 4096
pack_report: core.packedGitWindowSize = 33554432
pack_report: core.packedGitLimit = 268435456
pack_report: pack_used_ctr = 2
pack_report: pack_mmap_calls = 1
pack_report: pack_open_windows = 1 / 1
pack_report: pack_mapped = 253 / 253
---------------------------------------------------------------------

Thanks,
Stefano

#9 lore raw
Quoted 2 lines · Stefano Lattarini

OK, I cut & pasted your command; it ran successfully, with this output:

And your installed git version is the same as the one you are seeing the deadlock with?

#10 lore raw
Quoted 7 lines · Clemens Buchacher
Quoted 2 lines · Stefano Lattarini

OK, I cut & pasted your command; it ran successfully, with this output:

And your installed git version is the same as the one you are seeing the deadlock with?

No, but I see the same behaviour if I put '~/src/git/bin-wrappers' early in PATH:

$ git --version
git version 1.7.10.130.g36e6c
$ (cd localclone; git fast-export --use-done-feature  \
     --export-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
     --import-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
     ^refs/testgit/origin/master refs/heads/master) \
  | (cd server; git fast-import \
      --export-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
      --import-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks')

git-fast-import statistics:
---------------------------------------------------------------------
Alloc'd objects: 5000

Total objects:            3 (         0 duplicates                  )
      blobs  :            1 (         0 duplicates          0 deltas of          1 attempts)
      trees  :            1 (         0 duplicates          0 deltas of          1 attempts)
      commits:            1 (         0 duplicates          0 deltas of          0 attempts)
      tags   :            0 (         0 duplicates          0 deltas of          0 attempts)
Total branches:           1 (         1 loads     )
      marks:           1024 (         6 unique    )

atoms: 1
Memory total: 2294 KiB
pools: 2098 KiB
objects: 195 KiB
---------------------------------------------------------------------
pack_report: getpagesize() = 4096
pack_report: core.packedGitWindowSize = 33554432
pack_report: core.packedGitLimit = 268435456
pack_report: pack_used_ctr = 1
pack_report: pack_mmap_calls = 1
pack_report: pack_open_windows = 1 / 1
pack_report: pack_mapped = 254 / 254
---------------------------------------------------------------------

Regards,
Stefano

#11 lore raw
In reply to Stefano Lattarini

Hi Sverre,

The 'pushing to local repo' test of t5800 which pushes using git-remote-testgit.py results in a deadlock for Stefano. Invoking fast-export/fast-import manually seems to work, however. I don't know what else to try at this point.

I am pasting some relevant results below.

Quoted 7 lines

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD
Quoted 11 lines

[...]
Debug: Remote helper: -> export
trace: run_command: 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed
7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
trace: exec: 'git' 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
trace: built-in: git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master'
Got command 'export' with args ''
trace: built-in: git 'for-each-ref' 'refs/heads'
Debug: Remote helper: Waiting...
trace: exec: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'
trace: run_command: 'git-fast-import' '--quiet' '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

This is Stefano's output, at which point git fast-import hangs. On my box, fast-export runs a little later (after Got command 'export' with args ''), but I don't see how that would matter.

Below is the result from running fast-import/fast-export manually:

Quoted 61 lines · Stefano Lattarini
Quoted 18 lines · Clemens Buchacher

Hi Stefano,

Almost there. :-)

Quoted 8 lines · Stefano Lattarini
$ git 'fast-export' '--use-done-feature' \
      '--export-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '--import-marks=.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      '^refs/testgit/origin/master' 'refs/heads/master' \
   | git 'fast-import' \
         '--export-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         '--import-marks=/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks'

To simulate a git push, you have to run fast-export from localclone and fast-import from the server directory. I.e. starting out in t/trash directory.t5800-remote-helpers:

Quoted 8 lines
$ (cd localclone; git fast-export --use-done-feature \
      --export-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      --import-marks='.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/testgit.marks' \
      ^refs/testgit/origin/master refs/heads/master) |
  (cd server; git fast-import \
         --export-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks' \
         --import-marks='/devel/stefano/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/c6c0871f9a7f12cd3f51aa290fbed7c49f539a8c/git.marks')

OK, I cut & pasted your command; it ran successfully, with this output:

git-fast-import statistics:
---------------------------------------------------------------------
Alloc'd objects: 5000

Total objects:            3 (         0 duplicates                  )
      blobs  :            1 (         0 duplicates          0 deltas of          1 attempts)
      trees  :            1 (         0 duplicates          0 deltas of          1 attempts)
      commits:            1 (         0 duplicates          0 deltas of          0 attempts)
      tags   :            0 (         0 duplicates          0 deltas of          0 attempts)
Total branches:           1 (         1 loads     )
      marks:           1024 (         6 unique    )

atoms: 1
Memory total: 2294 KiB
pools: 2098 KiB
objects: 195 KiB
---------------------------------------------------------------------
pack_report: getpagesize() = 4096
pack_report: core.packedGitWindowSize = 33554432
pack_report: core.packedGitLimit = 268435456
pack_report: pack_used_ctr = 2
pack_report: pack_mmap_calls = 1
pack_report: pack_open_windows = 1 / 1
pack_report: pack_mapped = 253 / 253
---------------------------------------------------------------------

Thanks,
Stefano

Other possibly relevant information:

  $ hg --version | head -1
  Mercurial Distributed SCM (version 1.8.3) $ python --version
Quoted 8 lines
  $ python --version
  Python 2.7.2+
  $ /bin/sh --version | head -1
  GNU bash, version 4.1.5(1)-release (i486-pc-linux-gnu)
  $ git describe
  v1.7.10-167-gf245c01

Clemens

#12 lore raw
Quoted 6 lines · Clemens Buchacher

The 'pushing to local repo' test of t5800 which pushes using git-remote-testgit.py results in a deadlock for Stefano. Invoking fast-export/fast-import manually seems to work, however. I don't know what else to try at this point.

I am pasting some relevant results below.

Junio ran into the same problem before, so far no-one has been able to figure out why this is happening and/or under what circumstances.

Signature · 3 lines
Cheers,

Sverre Rabbelier
#13 lore raw
In reply to Clemens Buchacher

[email protected] wrote on Sun, 15 Apr 2012 14:51 +0200:

Quoted 5 lines

The 'pushing to local repo' test of t5800 which pushes using git-remote-testgit.py results in a deadlock for Stefano. Invoking fast-export/fast-import manually seems to work, however. I don't know what else to try at this point.

Quoted 8 lines

I am pasting some relevant results below.

Quoted 6 lines

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD

fast-export should say to fd 1 "feature done\nblob\n..."

fast-import is probably blocked on reading fd 0, hoping to find a sequence of commands

I too cannot reproduce the problem. Stefano, can you try this bigger hammer? We'll see if anything sticks out.

GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 strace -vf -s 2000 -o /tmp/strace.out git push

Then "bzip2 /tmp/strace.out" and attach /tmp/strace.out.bz2, please.

		-- Pete

A message that is not in the archive (sent off-list or not yet received): [email protected]

#15 lore raw

[email protected] wrote on Fri, 20 Apr 2012 13:16 +0200:

Quoted 35 lines · Pete Wyckoff
Quoted 20 lines

[email protected] wrote on Sun, 15 Apr 2012 14:51 +0200:

Quoted 5 lines

The 'pushing to local repo' test of t5800 which pushes using git-remote-testgit.py results in a deadlock for Stefano. Invoking fast-export/fast-import manually seems to work, however. I don't know what else to try at this point.

Quoted 8 lines

I am pasting some relevant results below.

Quoted 6 lines

expecting success:

        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
        GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD

fast-export should say to fd 1 "feature done\nblob\n..."

fast-import is probably blocked on reading fd 0, hoping to find a sequence of commands

Quoted 9 lines

I too cannot reproduce the problem. Stefano, can you try this bigger hammer? We'll see if anything sticks out.

GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 strace -vf -s 2000 -o /tmp/strace.out git push

Then "bzip2 /tmp/strace.out" and attach /tmp/strace.out.bz2, please.

		-- Pete

Here it is. Details of the git version I've used to do this test:

  $ git describe
  v1.7.10-207-g0bb2ee1
Quoted 16 lines
  $ git diff
  diff --git a/t/t5800-remote-helpers.sh b/t/t5800-remote-helpers.sh
  index 1c62001..770cda6 100755
  --- a/t/t5800-remote-helpers.sh
  +++ b/t/t5800-remote-helpers.sh
  @@ -68,7 +68,10 @@ test_expect_success 'pushing to local repo' '
          (cd localclone &&
          echo content >>file &&
          git commit -a -m three &&
  -       git push) &&
  +        GIT_TRACE=1 \
  +        GIT_TRANSPORT_HELPER_DEBUG=1 \
  +        GIT_DEBUG_TESTGIT=1 \
  +        strace -vf -s 2000 -o /tmp/strace.out git push) &&
          compare_refs localclone HEAD server HEAD
   '

Thank you. Adding the strace made that test work, and a later one hung with the same race condition. Here's a patch that describes the race, and adds a strategic sleep to make it easily reproducible.

Not sure yet what is the right way to fix this. And I don't know if it's just git-remote-testgit that has the problem because it forks an importer, or if other remote helpers would be similarly affected.

The easiest fix is to invoke "python -u" in
git-remote-testgit.py, or do

    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)

But I'm not sure if this works on all systems. We could also consider adding a handshake after "export", to give the helper time to get ready.

		-- Pete

--8<--

Quoted 1 line

From 4179e326d86b6ab9f9c7f79a9dbd03b8d81b6a6a Mon Sep 17 00:00:00 2001

From: Pete Wyckoff <[email protected]>
Date: Sat, 21 Apr 2012 14:57:31 -0400
Subject: [PATCH] demonstrate git-remote-testgit race

Test t5800-remote-helpers "pushing to local repo" can hang in a race condition between git push and git-remote-testgit.

On the writer side, "git push" invokes push_refs_with_export(), which sends to stdout the command "export\n" and immediately starts up "git fast-export". The latter writes its output stream to the same stdout.

On the reader side, remote helper "git-remote-testgit" reads from stdin to get its next command. It uses getc() to read characters from libc up until \n. Libc has buffered a potentially much larger chunk of stdin. When it sees the "export\n" command, it forks "git fast-import" to read the stream.

If fast-export is faster than git-remote-testgit + git fast-import, the fast-export output can end up in libc's buffer, rather than in git fast-import. The latter blocks on a now-empty stdin.

This patch demonstates the problem.

---
 git-remote-testgit.py     |    7 +++++++
 t/t5800-remote-helpers.sh |   17 +++++++++++++++++
 2 files changed, 24 insertions(+)
git-remote-testgit.py +7 -0
index 3dc4851..616e772 100644
@@ -22,6 +22,7 @@ except ImportError:
     _digest = sha.new
 import sys
 import os
+import time
 sys.path.insert(0, os.getenv("GITPYTHONLIB","."))
 
 from git_remote_helpers.util import die, debug, warn
@@ -204,6 +205,12 @@ def read_one_line(repo):
     """Reads and processes one command.
     """
 
+    sleepy = os.environ.get("GIT_REMOTE_TESTGIT_SLEEPY")
+    if sleepy:
+        debug("Sleeping %d sec before readline" % int(sleepy))
+        time.sleep(int(sleepy))
+        debug("Awake, to readline")
+
     line = sys.stdin.readline()
 
     cmdline = line
t/t5800-remote-helpers.sh +17 -0
index 1c62001..7555be6 100755
@@ -72,6 +72,23 @@ test_expect_success 'pushing to local repo' '
 	compare_refs localclone HEAD server HEAD
 '
 
+test_expect_failure 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&
+	(cd localclone2 &&
+	echo content >>file &&
+	git commit -a -m three &&
+	GIT_TRANSPORT_HELPER_DEBUG=1 GIT_REMOTE_TESTGIT_SLEEPY=2 timeout 10 strace -o trace.out -f git push
+	ret=$? &&
+	if [ $ret -eq 124 ]; then
+	    echo "Check for too much input in export line" &&
+	    grep "read(0, .export" trace.out ; true
+	fi &&
+	exit $ret) &&
+	compare_refs localclone2 HEAD server2 HEAD
+'
+
 test_expect_success 'synch with changes from localclone' '
 	(cd clone &&
 	 git pull)
Signature · 1 line
1.7.10.57.g7fa2a.dirty
#16 lore raw

Hi Pete,

Thanks for solving the mystery.

Quoted 6 lines · Pete Wyckoff

Not sure yet what is the right way to fix this. And I don't know if it's just git-remote-testgit that has the problem because it forks an importer, or if other remote helpers would be similarly affected.

Quoted 6 lines

The easiest fix is to invoke "python -u" in
git-remote-testgit.py, or do

    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)

But I'm not sure if this works on all systems.

Which part are you worried about? Maybe the patch below is more portable?

Quoted 2 lines

We could also consider adding a handshake after "export", to give the helper time to get ready.

Not sure I understand. The helper is throwing away some input. It seems to me there is nothing one can do to prevent such brokeness.

It would be nice if the deadlock could be detected and if git would time out in such a case, instead of hanging forever. But rather long delays can also be the result of the remote helper legimitately waiting for data from a slow network.

Clemens
---

git-remote-testgit.py +18 -4
index 616e772..bdd1116 100644
@@ -135,6 +135,22 @@ def update_local_repo(repo):
     return repo
 
 
+def read_line_fd(fd):
+    """Read from fd until end of line or EOF, and no further.
+    """
+
+    line = ''
+
+    while True:
+        c = os.read(fd, 1)
+        if c == '':
+            break
+        line += c
+        if c == '\n':
+            break
+
+    return line
+
 def do_import(repo, args):
     """Exports a fast-import stream from testgit for git to import.
     """
@@ -149,7 +165,7 @@ def do_import(repo, args):
     refs = [ref]
 
     while True:
-        line = sys.stdin.readline()
+        line = read_line_fd(sys.stdin.fileno())
         if line == '\n':
             break
         if not line.startswith('import '):
@@ -211,9 +227,7 @@ def read_one_line(repo):
         time.sleep(int(sleepy))
         debug("Awake, to readline")
 
-    line = sys.stdin.readline()
-
-    cmdline = line
+    cmdline = read_line_fd(sys.stdin.fileno())
 
     if not cmdline:
         warn("Unexpected EOF")
Signature · 1 line
1.7.10
#17 lore raw

[email protected] wrote on Sun, 22 Apr 2012 01:35 +0200:

Quoted 14 lines

Hi Pete,

Thanks for solving the mystery.

Quoted 9 lines · Pete Wyckoff

Not sure yet what is the right way to fix this. And I don't know if it's just git-remote-testgit that has the problem because it forks an importer, or if other remote helpers would be similarly affected.

The easiest fix is to invoke "python -u" in
git-remote-testgit.py, or do

Quoted 6 lines
Quoted 3 lines
    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)

But I'm not sure if this works on all systems.

Which part are you worried about? Maybe the patch below is more portable?

Your way works. But it doesn't handle universal newlines. I don't know if the windows platforms turn that on for stdio. In fact, I'm not sure we should be worried about sys.stdin buffering on windows at all.

Quoted 5 lines
Quoted 2 lines

We could also consider adding a handshake after "export", to give the helper time to get ready.

Not sure I understand. The helper is throwing away some input. It seems to me there is nothing one can do to prevent such brokeness.

The handshake would give the helper time to get its streams straightened up. It would do something like:

read "export\n"
fork importer, listening to stdin
write "export-ready\n" to stdout

And git push would wait for the "export-ready" line before it unleases the stream from fast-export. But as Sverre said, that's a protocol change, which is more difficult. And maybe not warranted if we think this can also be attributed to helper brokenness.

I think we should reopen stdin like this to fix the problem now. I'll investigate if it exists on windows too, and see if it is possible to fix there too.

Quoted 4 lines

It would be nice if the deadlock could be detected and if git would time out in such a case, instead of hanging forever. But rather long delays can also be the result of the remote helper legimitately waiting for data from a slow network.

Tough, generally.

		-- Pete
Quoted 53 lines

Clemens
---

git-remote-testgit.py +18 -4
index 616e772..bdd1116 100644
@@ -135,6 +135,22 @@ def update_local_repo(repo):
     return repo
 
 
+def read_line_fd(fd):
+    """Read from fd until end of line or EOF, and no further.
+    """
+
+    line = ''
+
+    while True:
+        c = os.read(fd, 1)
+        if c == '':
+            break
+        line += c
+        if c == '\n':
+            break
+
+    return line
+
 def do_import(repo, args):
     """Exports a fast-import stream from testgit for git to import.
     """
@@ -149,7 +165,7 @@ def do_import(repo, args):
     refs = [ref]
 
     while True:
-        line = sys.stdin.readline()
+        line = read_line_fd(sys.stdin.fileno())
         if line == '\n':
             break
         if not line.startswith('import '):
@@ -211,9 +227,7 @@ def read_one_line(repo):
         time.sleep(int(sleepy))
         debug("Awake, to readline")
 
-    line = sys.stdin.readline()
-
-    cmdline = line
+    cmdline = read_line_fd(sys.stdin.fileno())
 
     if not cmdline:
         warn("Unexpected EOF")
Signature · 1 line
1.7.10
#18 lore raw

PATCH 1/1 git-remote-testgit: fix race when spawning fast-import

In reply to Pete Wyckoff

Test "pushing to local repo" in t5800-remote-helpers can hang in a race condition between git push and git-remote-testgit.

On the writer side, "git push" invokes push_refs_with_export(), which sends to stdout the command "export\n" and immediately starts up "git fast-export". The latter writes its output stream to the same stdout.

On the reader side, remote helper "git-remote-testgit" reads from stdin to get its next command. It uses getc() to read characters from libc up until \n. Libc has buffered a potentially much larger chunk of stdin. When it sees the "export\n" command, it forks "git fast-import" to read the stream.

If fast-export finishes before git fast-import starts, the fast-export output can end up in libc's buffer in git-remote-testgit, rather than in git fast-import. The latter hangs indefinitely on a now-empty stdin.

Fix this by setting stdin to unbuffered.

---

This is the one that might be suitable for upstream. It fixes the problem with this particular remote helper.

 git-remote-testgit.py     |    7 +++++++
 t/t5800-remote-helpers.sh |   11 +++++++++++
 2 files changed, 18 insertions(+)
git-remote-testgit.py +7 -0
index 3dc4851..5f3ebd2 100644
@@ -22,6 +22,7 @@ except ImportError:
     _digest = sha.new
 import sys
 import os
+import time
 sys.path.insert(0, os.getenv("GITPYTHONLIB","."))
 
 from git_remote_helpers.util import die, debug, warn
@@ -204,6 +205,11 @@ def read_one_line(repo):
     """Reads and processes one command.
     """
 
+    sleepy = os.environ.get("GIT_REMOTE_TESTGIT_SLEEPY")
+    if sleepy:
+        debug("Sleeping %d sec before readline" % int(sleepy))
+        time.sleep(int(sleepy))
+
     line = sys.stdin.readline()
 
     cmdline = line
@@ -258,6 +264,7 @@ def main(args):
 
     more = True
 
+    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)
     while (more):
         more = read_one_line(repo)
 
t/t5800-remote-helpers.sh +11 -0
index 1c62001..cdcee83 100755
@@ -72,6 +72,17 @@ test_expect_success 'pushing to local repo' '
 	compare_refs localclone HEAD server HEAD
 '
 
+test_expect_success 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&
+	(cd localclone2 &&
+	echo content >>file &&
+	git commit -a -m three &&
+	GIT_REMOTE_TESTGIT_SLEEPY=2 git push) &&
+	compare_refs localclone2 HEAD server2 HEAD
+'
+
 test_expect_success 'synch with changes from localclone' '
 	(cd clone &&
 	 git pull)
Signature · 1 line
1.7.10.57.g22c0b.dirty
#19 lore raw

Re: [PATCH] git-remote-testgit: fix race when spawning fast-import

git-remote-testgit.py def main(args): · line 269

Quoted 8 lines · Pete Wyckoff
git-remote-testgit.py +1 -0
@@ -258,6 +264,7 @@ def main(args):
 
     more = True
 
+    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)
     while (more):
         more = read_one_line(repo)

There's another read in do_import(). I am not sure if it also suffers from this race condition, but it certainly has the potential.

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 84

Quoted 10 lines
t/t5800-remote-helpers.sh +10 -0
+test_expect_success 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&
+	(cd localclone2 &&
+	echo content >>file &&
+	git commit -a -m three &&
+	GIT_REMOTE_TESTGIT_SLEEPY=2 git push) &&
+	compare_refs localclone2 HEAD server2 HEAD
+'

Should this test be running unconditionally? It will delay the otherwise almost instant test by 2 seconds.

#20 lore raw

Re: [PATCH] git-remote-testgit: fix race when spawning fast-import

[email protected] wrote on Sun, 22 Apr 2012 01:42 +0200:

Quoted 12 lines · Pete Wyckoff

git-remote-testgit.py def main(args): · line 269

Quoted 8 lines
git-remote-testgit.py +1 -0
@@ -258,6 +264,7 @@ def main(args):
 
     more = True
 
+    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)
     while (more):
         more = read_one_line(repo)

There's another read in do_import(). I am not sure if it also suffers from this race condition, but it certainly has the potential.

It just takes one reopen of stdin for the whole program. So that one is handled automatically too.

Quoted 5 lines
Quoted 5 lines
t/t5800-remote-helpers.sh +5 -0
+test_expect_success 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&
+	(cd localclone2 &&
Quoted 8 lines

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 84

Quoted 5 lines
t/t5800-remote-helpers.sh +5 -0
+	echo content >>file &&
+	git commit -a -m three &&
+	GIT_REMOTE_TESTGIT_SLEEPY=2 git push) &&
+	compare_refs localclone2 HEAD server2 HEAD
+'

Should this test be running unconditionally? It will delay the otherwise almost instant test by 2 seconds.

More like 6 seconds, in fact, for all three interactions in "git push". I'll change the test to add a prereq on TOOSLOW; is there a better way to leave a test in to document the issue, but have it skipped?

		-- Pete
#21 lore raw

Re: [PATCH] git-remote-testgit: fix race when spawning fast-import

Quoted 9 lines · Pete Wyckoff

[email protected] wrote on Sun, 22 Apr 2012 01:42 +0200:

Quoted 3 lines

Should this test be running unconditionally? It will delay the otherwise almost instant test by 2 seconds.

More like 6 seconds, in fact, for all three interactions in "git push". I'll change the test to add a prereq on TOOSLOW; is there a better way to leave a test in to document the issue, but have it skipped?

Sounds good to me.

#22 lore raw

Re: [PATCH] git-remote-testgit: fix race when spawning fast-import

In reply to Pete Wyckoff
Quoted 25 lines · Pete Wyckoff

Fix this by setting stdin to unbuffered.

---

This is the one that might be suitable for upstream. It fixes the problem with this particular remote helper.

 git-remote-testgit.py     |    7 +++++++
 t/t5800-remote-helpers.sh |   11 +++++++++++
 2 files changed, 18 insertions(+)
git-remote-testgit.py +1 -0
index 3dc4851..5f3ebd2 100644
@@ -22,6 +22,7 @@ except ImportError:
     _digest = sha.new
 import sys
 import os
+import time
 sys.path.insert(0, os.getenv("GITPYTHONLIB","."))
 
 from git_remote_helpers.util import die, debug, warn

git-remote-testgit.py def read_one_line(repo): · line 212

Quoted 8 lines
git-remote-testgit.py +5 -0
@@ -204,6 +205,11 @@ def read_one_line(repo):
     """Reads and processes one command.
     """
 
+    sleepy = os.environ.get("GIT_REMOTE_TESTGIT_SLEEPY")
+    if sleepy:
+        debug("Sleeping %d sec before readline" % int(sleepy))
+        time.sleep(int(sleepy))
+

If I understand your explanation correctly, the primary purpose of the remote-testgit is to test the parts of the system that talk to remote helpers that are used in production in the t/t5800 script, and this "sleep" is to make it easier to trigger the particular bug you fixed in *this* script. The bug is _not_ in the parts of the system being tested, but is in this test scaffolding.

If that is the case, then it should not be enabled unconditionally. When somebody wants to see if remote-testgit was broken again (perhaps after observing occassional hangs), the environment should be set when running the test, but not in t5800.

#23 lore raw

PATCH v2 1/1 git-remote-testgit: fix race when spawning fast-import

Test "pushing to local repo" in t5800-remote-helpers can hang due to a race condition in git-remote-testgit. Fix it by setting stdin to unbuffered.

On the writer side, "git push" invokes push_refs_with_export(), which sends to stdout the command "export\n" and immediately starts up "git fast-export". The latter writes its output stream to the same stdout.

On the reader side, remote helper "git-remote-testgit" reads from stdin to get its next command. It uses getc() to read characters from libc up until \n. Libc has buffered a potentially much larger chunk of stdin. When it sees the "export\n" command, it forks "git fast-import" to read the stream.

If fast-export finishes before git fast-import starts, the fast-export output can end up in libc's buffer in git-remote-testgit, rather than in git fast-import. The latter hangs indefinitely on a now-empty stdin.

---
[email protected] wrote on Sat, 21 Apr 2012 21:50 -0700:

Quoted 6 lines

If I understand your explanation correctly, the primary purpose of the remote-testgit is to test the parts of the system that talk to remote helpers that are used in production in the t/t5800 script, and this "sleep" is to make it easier to trigger the particular bug you fixed in *this* script. The bug is _not_ in the parts of the system being tested, but is in this test scaffolding.

Indeed. I tried to make that more obvious in the commit message.

Quoted 4 lines

If that is the case, then it should not be enabled unconditionally. When somebody wants to see if remote-testgit was broken again (perhaps after observing occassional hangs), the environment should be set when running the test, but not in t5800.

Clemens suggested disabling the test by default, as I've done here. I think it would be okay to remove it entirely, too.

		-- Pete
 git-remote-testgit.py     |    7 +++++++
 t/t5800-remote-helpers.sh |   14 ++++++++++++++
 2 files changed, 21 insertions(+)
git-remote-testgit.py +7 -0
index 3dc4851..5f3ebd2 100644
@@ -22,6 +22,7 @@ except ImportError:
     _digest = sha.new
 import sys
 import os
+import time
 sys.path.insert(0, os.getenv("GITPYTHONLIB","."))
 
 from git_remote_helpers.util import die, debug, warn
@@ -204,6 +205,11 @@ def read_one_line(repo):
     """Reads and processes one command.
     """
 
+    sleepy = os.environ.get("GIT_REMOTE_TESTGIT_SLEEPY")
+    if sleepy:
+        debug("Sleeping %d sec before readline" % int(sleepy))
+        time.sleep(int(sleepy))
+
     line = sys.stdin.readline()
 
     cmdline = line
@@ -258,6 +264,7 @@ def main(args):
 
     more = True
 
+    sys.stdin = os.fdopen(sys.stdin.fileno(), 'r', 0)
     while (more):
         more = read_one_line(repo)
 
t/t5800-remote-helpers.sh +14 -0
index 1c62001..85a8042 100755
@@ -72,6 +72,20 @@ test_expect_success 'pushing to local repo' '
 	compare_refs localclone HEAD server HEAD
 '
 
+# Generally, skip this test.  It demonstrates a now-fixed
+# race in git-remote-testgit, but is too slow to leave in
+# for general use.
+test_expect_success DEBUG_TESTGIT_RACE 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&
+	(cd localclone2 &&
+	echo content >>file &&
+	git commit -a -m three &&
+	GIT_REMOTE_TESTGIT_SLEEPY=2 git push) &&
+	compare_refs localclone2 HEAD server2 HEAD
+'
+
 test_expect_success 'synch with changes from localclone' '
 	(cd clone &&
 	 git pull)
Signature · 1 line
1.7.10.57.g437cb.dirty
#24 lore raw

Re: [PATCHv2] git-remote-testgit: fix race when spawning fast-import

Quoted 2 lines · Pete Wyckoff

Clemens suggested disabling the test by default, as I've done here. I think it would be okay to remove it entirely, too.

Ok.

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 81

Quoted 7 lines
t/t5800-remote-helpers.sh +7 -0
+# Generally, skip this test.  It demonstrates a now-fixed
+# race in git-remote-testgit, but is too slow to leave in
+# for general use.
+test_expect_success DEBUG_TESTGIT_RACE 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&

Shouldn't test_when_finished come before these two commands? Otherwise server2 or localclone2 directories will be left behind when they fail before control reaches it...

#25 lore raw

Re: [PATCHv2] git-remote-testgit: fix race when spawning fast-import

[email protected] wrote on Sun, 22 Apr 2012 19:40 -0700:

Quoted 7 lines
Quoted 2 lines · Pete Wyckoff

Clemens suggested disabling the test by default, as I've done here. I think it would be okay to remove it entirely, too.

Ok.

Quoted 11 lines

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 81

Quoted 7 lines
t/t5800-remote-helpers.sh +7 -0
+# Generally, skip this test.  It demonstrates a now-fixed
+# race in git-remote-testgit, but is too slow to leave in
+# for general use.
+test_expect_success DEBUG_TESTGIT_RACE 'racily pushing to local repo' '
+	cp -a server server2 &&
+	git clone "testgit::${PWD}/server2" localclone2 &&
+	test_when_finished "rm -rf server2 localclone2" &&

Shouldn't test_when_finished come before these two commands? Otherwise server2 or localclone2 directories will be left behind when they fail before control reaches it...

Yes, you're right.

		-- Pete
#26 lore raw
In reply to Clemens Buchacher
Quoted 19 lines · Clemens Buchacher
Quoted 4 lines · Stefano Lattarini

Debug: Remote helper: -> export
Got command 'export' with args ''
Debug: Remote helper: Waiting...

Hmm. Looks like fast-import and fast-export are in a deadlock. It's probably time to let the experts take over. But if you want to indulge me further, you could try again with GIT_TRACE=1. That should give you the arguments to use for the fast-export and fast-import commands right before it hangs. Then run ./t5800-remote-helpers.sh -i with the following change to make it abort right before git push:

t/t5800-remote-helpers.sh +0 -0
index 1c62001..c4855e9 100755

t/t5800-remote-helpers.sh test_expect_success 'pushing to local repo' ' · line 75

Quoted 9 lines
t/t5800-remote-helpers.sh +2 -1
@@ -68,7 +68,8 @@ test_expect_success 'pushing to local repo' '
        (cd localclone &&
        echo content >>file &&
        git commit -a -m three &&
-       git push) &&
+       false &&
+       GIT_TRACE=1 GIT_TRANSPORT_HELPER_DEBUG=1 GIT_DEBUG_TESTGIT=1 git push) &&
        compare_refs localclone HEAD server HEAD
 '
 

As your later reply pointed out: yes, I had missed the remaining part of your message :-( Sorry for the confusion. I'm going to reply to it now.

Quoted 25 lines

You can manually now run fast-export using the arguments from the first run, for example in my case:

cd trash\ directory.t5800-remote-helpers
(cd localclone; git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '--import-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master') |

That should output:

feature done
blob
mark :5
data 24
content
content
content

commit refs/heads/master
mark :6
author A U Thor <[email protected]> 1334451823 +0000 committer C O Mitter <[email protected]> 1334451823 +0000 data 6
three
from :4
M 100644 :5 file

Quoted 3 lines

done

Nope, for me it fails with status '128' and with this error message:

fatal: cannot read '.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks': No such file or directory

Quoted 7 lines

Finally, you can manually pipe fast-export to fast-import, again using the arguments from the first run:

cd trash\ directory.t5800-remote-helpers
(cd localclone; git 'fast-export' '--use-done-feature' '--export-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '--import-marks=.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks' '^refs/testgit/origin/master' 'refs/heads/master') |
(cd server; git fast-import '--quiet' '--export-marks=/home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks' '--import-marks=/home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks')

This fails with the following message:

fatal: cannot read '.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/testgit.marks': No such file or directory
fatal: cannot read '/home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks': No such file or directory
fast-import: dumping crash report to .git/fast_import_crash_19819
error: Unable to write marks file /home/drizzd/src/git/t/trash directory.t5800-remote-helpers/localclone/.git/info/fast-import/cbf054fee258a261ee43ebdc835f0da71b3d1562/git.marks: No such file or directory

Quoted 4 lines

If the fast-export output is the same, and if the last command also hangs for you, then we can start debugging fast-import.

Clemens

Thanks,
Stefano