[[!comment format=mdwn
 username="joey"
 subject="""comment 23"""
 date="2018-11-05T19:14:44Z"
 content="""
Straces confirm the hanging git-annex-shell never gets to the point of
sending "DATA". It does receive the "GET". 

annex.pidlock is set. That's unusual. It seems likely it's got
something to do with the problem, because pidlocks and concurrency don't
really mix; at best one git-annex process can hold the pid lock, so
other processes will need to wait, and could also time out and fail
to take the pid lock. 

Yeah: Setting annex.pidlock, I can reproduce the hang!

The strace of the non-hanging process shows it took the pid lock and dropped it,
twice. So the other process should have been able to take the pid lock too.

The hanging process does something around taking the pid lock just before
it hangs.

It checks the side lock, which is locked (this is `trySideLock`):

	6219  openat(AT_FDCWD, "/dev/shm/08d71513c120bda153ed3b773c1e59ff_BIDS_dbic_QA_.git_annex_pidlock.lck", O_RDWR|O_CREAT, 0666 <unfinished ...>
	6286  futex(0x555f91523d2c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
	6219  <... openat resumed> )            = 11
	6219  fcntl(11, F_GETFD)                = 0
	6219  fcntl(11, F_SETFD, FD_CLOEXEC)    = 0
	6219  fcntl(11, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = -1 EAGAIN (Resource temporarily unavailable)
	6219  close(11)                         = 0

Then it checks the pid lock (this is `tryLock` when
`linkToLock` fails due to the side lock not being held):

	6219  openat(AT_FDCWD, "XXX/.git/annex/locktmp6219-0", O_RDWR|O_CREAT|O_EXCL|O_NOCTTY|O_NONBLOCK, 0600) = 11
	6219  openat(AT_FDCWD, "XXX/.git/annex/pidlock", O_RDONLY|O_NOCTTY|O_NONBLOCK) = 11
	6219  fstat(11, {st_mode=S_IFREG|0444, st_size=52, ...}) = 0
	6219  ioctl(11, TCGETS, 0x7ffd3c59ba90) = -1 ENOTTY (Inappropriate ioctl for device)
	6219  uname({sysname="Linux", nodename="XXX", ...}) = 0
	6219  stat("XXX/.git/annex/locktmp6219-0", {st_mode=S_IFREG|0444, st_size=52, ...}) = 0
	6219  read(11, "PidLock {lockingPid = 6221, lock"..., 8192) = 52

And gives up without overwriting it:

	6219  unlink("XXX/.git/annex/locktmp6219-0") = 0
	6219  unlink("XXX/.git/annex/locktmp6219-0") = -1 ENOENT (No such file or directory)

And then hangs waiting on stdin, it looks lile:

	6219  poll([{fd=0, events=POLLIN}], 1, 0) = 0 (Timeout)
	6219  epoll_ctl(3, EPOLL_CTL_MOD, 0, {EPOLLIN|EPOLLONESHOT, {u32=0, u64=0}}) = 0
	6219  futex(0x555f91523c0c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
	6285  <... read resumed> "\1\0\0\0\0\0\0\0", 8) = 8
	6285  read(4, "\1\0\0\0\0\0\0\0", 8)    = 8
	6285  read(4, "\1\0\0\0\0\0\0\0", 8)    = 8
	6285  read(4, "\1\0\0\0\0\0\0\0", 8)    = 8
	6285  read(4, "\1\0\0\0\0\0\0\0", 8)    = 8

Seems it was not in `waitLock`, because that should loop and `tryLock` again once
per second.

So, maybe some part of git-annex is calling `tryLock`, and when it fails, it
somehow ends up blocked waiting for more protocol commands?

My next step now that I can reproduce it is to manually take the pid lock,
and run git-annex-shell p2pstdio, and see if it's indeed reading more commands from
stdin despite not responding to GET, or is sending an error or what.
"""]]
