error: git-annex filter-process died of signal 15

Please describe the problem.

When doing

git checkout 3b18836

on a very large repository, where tens of thousands of files will be changed, I get many

error: external filter 'git-annex filter-process' failed error: git-annex filter-process died of signal 15

and finally

git-annex: git: createProcess: runInteractiveProcess: pipe: resource exhausted (Too many open files) fatal: the remote end hung up unexpectedly

What steps will reproduce the problem?

git checkout on a really big commit.

What version of git-annex are you using? On what operating system?

The system and all the SW should be up to date.

% git --version
git version 2.34.1

% git annex version
git-annex version: 10.20220322-1~ndall+1 build flags: Assistant Webapp Pairing Inotify DBus DesktopNotify TorrentParser MagicMime Feeds Testsuite S3 WebDAV dependency versions: aws-0.22 bloomfilter-2.0.1.0 cryptonite-0.26 DAV-1.3.4 feed-1.3.0.1 ghc-8.8.4 http-client-0.6.4.1 persistent-sqlite-2.10.6.2 torrent-10000.1.1 uuid-1.3.13 yesod-1.6.1.0 key/value backends: SHA256E SHA256 SHA512E SHA512 SHA224E SHA224 SHA384E SHA384 SHA3_256E SHA3_256 SHA3_512E SHA3_512 SHA3_224E SHA3_224 SHA3_384E SHA3_384 SKEIN256E SKEIN256 SKEIN512E SKEIN512 BLAKE2B256E BLAKE2B256 BLAKE2B512E BLAKE2B512 BLAKE2B160E BLAKE2B160 BLAKE2B224E BLAKE2B224 BLAKE2B384E BLAKE2B384 BLAKE2BP512E BLAKE2BP512 BLAKE2S256E BLAKE2S256 BLAKE2S160E BLAKE2S160 BLAKE2S224E BLAKE2S224 BLAKE2SP256E BLAKE2SP256 BLAKE2SP224E BLAKE2SP224 SHA1E SHA1 MD5E MD5 WORM URL X* remote types: git gcrypt p2p S3 bup directory rsync web bittorrent webdav adb tahoe glacier ddar git-lfs httpalso borg hook external operating system: linux x86_64 supported repository versions: 8 9 10 upgrade supported from repository versions: 0 1 2 3 4 5 6 7 8 9 10 local repository version: 9

% uname -a
Linux 5.15.0-33-generic #34-Ubuntu SMP Wed May 18 13:34:26 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

% cat /etc/os-release
PRETTY_NAME="Ubuntu 22.04 LTS" NAME="Ubuntu" VERSION_ID="22.04" VERSION="22.04 LTS (Jammy Jellyfish)" VERSION_CODENAME=jammy ID=ubuntu ID_LIKE=debian HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" UBUNTU_CODENAME=jammy

The computer has 128GB of main memory, and so is not running out of that.

This is a large repository:

du -sh . p 43G .

(62)% du -sh .git
42G .git

(63)% du -sh .git/annex
19G .git/annex

% git gc
Enumerating objects: 375565, done. Counting objects: 100% (375565/375565), done. Delta compression using up to 12 threads Compressing objects: 100% (153675/153675), done. Writing objects: 100% (375565/375565), done. Total 375565 (delta 215701), reused 364628 (delta 207259), pack-reused 0 73.38s real 97.69s user 4.93s system 139% 0,0 socket 13753 mem git gc

I'm trying to recover from a mess caused by creating a new remote repository, making it shallow to save space, and updating it by mounting it on a local system with sshfs, etc. That caused an unintended rebase messing things up, e.g., git log shows most of the commits vanished (merged?). So I was trying to go back to an earlier, good, commit. However that requires changing, basically, everything. And that seems to be too big a change for git annex to process.

FWIW, I'm not using lfs.

Please provide any additional information below.

# If you can, paste a complete transcript of the problem occurring here.
# If the problem is with the git-annex assistant, paste in .git/annex/daemon.log


# End of transcript or log.

Have you had any luck using git-annex before? (Sometimes we get tired of reading bug reports all day and a lil' positive end note does wonders)

Otherwise, it's great.

fixed --Joey

RSS Atom

comment 1

How big a commit are we talking here, in terms of number of files added/changed?

I've tried with 10000 modified files and not seen a problem IIRC.

Also, signal 15 is SIGTERM, which would be a strange signal to happen unless it were ctrl-c'd.

Final weird thing is "fatal: the remote end hung up unexpectedly", since that would indicate a git fetch was running, and git-annex certianly does not fetch..

Comment by joey — Wed Jun 29 16:13:25 2022

Remove comment

comment 3

I also saw this when adding a single file to git:

joey@darkstar:/tmp/a1>touch .foo.lck
joey@darkstar:/tmp/a1>git add .foo.lck 
error: external filter 'git-annex filter-process' failed
error: git-annex filter-process died of signal 15

But, I have not succeeded to reproduce that again. This was in a v9 repository BTW.

Comment by joey — Wed Jul 13 20:32:03 2022

Remove comment

comment 4

Feeling like this is most likley a pkt-line protocol bug in git-annex, and probably one inovlving empty files. Both because of the prior comment with the empty file and it turns out there is also an empty file in my first reproducer.

Here is a GIT_TRACE_PACKET=1 log when reproducing it. I have omitted the actual content of my files..

16:30:18.248308 pkt-line.c:80           packet:          git> command=smudge
16:30:18.248335 pkt-line.c:80           packet:          git> pathname=new/.updater
16:30:18.248344 pkt-line.c:80           packet:          git> treeish=fbbe4045871fb749299b4484862645bd9a7f175a
16:30:18.248352 pkt-line.c:80           packet:          git> blob=dd75da379e8a2cad5a793d352e7def865d65158d
16:30:18.248358 pkt-line.c:80           packet:          git> 0000
16:30:18.248397 pkt-line.c:80           packet:          git> #!/bin/sh....
16:30:18.248409 pkt-line.c:80           packet:          git> 0000
16:30:18.248637 pkt-line.c:80           packet:          git< status=success
16:30:18.248728 pkt-line.c:80           packet:          git< 0000
16:30:18.248806 pkt-line.c:80           packet:          git< #!/bin/sh....
16:30:18.248818 pkt-line.c:80           packet:          git< 0000
16:30:18.248826 pkt-line.c:80           packet:          git< 0000
16:30:18.248985 pkt-line.c:80           packet:          git> command=smudge
16:30:18.249007 pkt-line.c:80           packet:          git> pathname=new/.updater.lock
16:30:18.249017 pkt-line.c:80           packet:          git> treeish=fbbe4045871fb749299b4484862645bd9a7f175a
16:30:18.249024 pkt-line.c:80           packet:          git> blob=e69de29bb2d1d6434b8b29ae775ad8c2e48c5391
16:30:18.249031 pkt-line.c:80           packet:          git> 0000
16:30:18.249037 pkt-line.c:80           packet:          git> 0000
16:30:18.249245 pkt-line.c:80           packet:          git< status=success
16:30:18.249262 pkt-line.c:80           packet:          git< 0000
16:30:18.249270 pkt-line.c:80           packet:          git< 0000
16:30:18.249277 pkt-line.c:80           packet:          git< 0000
16:30:18.280842 pkt-line.c:80           packet:          git> command=smudge
16:30:18.280882 pkt-line.c:80           packet:          git> pathname=new/cleanup
16:30:18.280891 pkt-line.c:80           packet:          git> treeish=fbbe4045871fb749299b4484862645bd9a7f175a
16:30:18.280898 pkt-line.c:80           packet:          git> blob=baad2545defeae59f526ea3d64174398899cb9cc
16:30:18.280904 pkt-line.c:80           packet:          git> 0000
16:30:18.280932 pkt-line.c:80           packet:          git> #!/bin/sh...
16:30:18.280942 pkt-line.c:80           packet:          git> 0000
16:30:18.280953 pkt-line.c:80           packet:          git< 0000
error: external filter 'git-annex filter-process' failed
error: git-annex filter-process died of signal 15

Now, from git's perspective, the last response of "0000" does look wrong. It should have been "status=success" followed by "0000" and then the file content, and then "0000" and "0000" again.

But as seen in the strace, git-annex sends more than that.

My guess is that git-annex is sending one 0000 too many for an empty file.

Comment by joey — Wed Jul 13 20:35:53 2022

Remove comment

comment 5

Indeed, I put in a special case for empty files and solved this!

Comment by joey — Wed Jul 13 21:11:07 2022

Remove comment

comment 2 5ebfc18008cf4bc21ffce57067314fc0

[[!comment format=mdwn username="joey" subject="""comment 2""" date="2022-07-13T19:53:44Z" content=""" Just reproduced this. In my big repo, I had commit eab6ac8b34be1d7c36df2a2f41a9414cf5908041 checked out and ran `git reset --hard fbbe4045871f` Git reported that it updated 112465 files, and near to the beginning, filter-process died of signal 15. Even better, it is reproducible, going back to that starting commit and running that command again works every time! And I got a strace too. Here is the git command: write(5, "0013command=smudge\n", 19) = 19 write(5, "0019pathname=new/cleanup\n", 25) = 25 write(5, "0035treeish=fbbe4045871fb749299b"..., 53) = 53 write(5, "0032blob=baad2545defeae59f526ea3"..., 50) = 50 write(5, "0000", 4) = 4 write(5, "0322", 4) = 4 write(5, "#!/bin/sh\n\ngit commit -m 'pre cl"..., 798) = 798 write(5, "0000", 4) = 4 read(6, "0000", 4) = 4 rt_sigaction(SIGPIPE, {sa_handler=0x563cf8debb50, sa_mask=[PIPE], sa_flags=SA_RES TORER|SA_RESTART, sa_restorer=0x7fab5717c920}, {sa_handler=SIG_IGN, sa_mask=[PIPE ], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fab5717c920}, 8) = 0 write(2, "error: external filter 'git-anne"..., 57) = 57 kill(1638045, SIGTERM) = 0 So git sends SIGTERM when it gets unhappy with the response it got from git-annex filter-process. Here is where git runs git-annex filter-process via the shell: execve("/bin/sh", ["/bin/sh", "-c", "git-annex filter-process", "git-annex filter-process"], 0x563cfacbfb40 /* 68 vars */) = 0 ... newfstatat(AT_FDCWD, "/home/joey/bin/git-annex", {st_mode=S_IFREG|0755, st_size=72524080, ...}, 0) = 0 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], NULL, 8) = 0 vfork() = 1631132 rt_sigprocmask(SIG_SETMASK, [], ~[KILL STOP RTMIN RT_1], 8) = 0 wait4(-1, 0x7fff910d697c, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=1631129, si_uid=1000} --- +++ killed by SIGTERM +++ But the actual git-annex process read the last thing git wrote to it, replied, and keeps running until it later reads an EOF from git. write(1, "0000", 4) = 4 poll([{fd=0, events=POLLIN}], 1, 0) = 0 (Timeout) epoll_ctl(4, EPOLL_CTL_MOD, 0, {EPOLLIN|EPOLLONESHOT, {u32=0, u64=287065581021036544}}) = 0 futex(0x67fe568, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0 futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0 futex(0x67fe68c, FUTEX_WAKE_PRIVATE, 1) = 1 read(0, "0013command=smudge\n0019pathname=new/cleanup\n0035treeish=fbbe4045871fb749299b4484862645bd9a7f175a\n0032blob=baad2545defeae59f526ea3d64174398899cb9cc\n00000322", 8192) = 155 poll([{fd=0, events=POLLIN}], 1, 0) = 1 ([{fd=0, revents=POLLIN}]) futex(0x67fe688, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x67fe690, FUTEX_WAKE_PRIVATE, 1) = 0 read(0, "#!/bin/sh....", 8192) = 802 futex(0x67fe56c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) futex(0x67fe570, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable) futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0 poll([{fd=1, events=POLLOUT}], 1, 0) = 1 ([{fd=1, revents=POLLOUT}]) futex(0x67fe68c, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x67fe690, FUTEX_WAKE_PRIVATE, 1) = 0 write(1, "0013status=success\n", 19) = 19 futex(0x67fe568, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0 futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0 poll([{fd=1, events=POLLOUT}], 1, 0) = 1 ([{fd=1, revents=POLLOUT}]) write(1, "0000", 4) = 4 poll([{fd=1, events=POLLOUT}], 1, 0) = 1 ([{fd=1, revents=POLLOUT}]) write(1, "0322#!/bin/sh...", 802) = 802 poll([{fd=1, events=POLLOUT}], 1, 0) = 1 ([{fd=1, revents=POLLOUT}]) write(1, "0000", 4) = 4 poll([{fd=1, events=POLLOUT}], 1, 0) = 1 ([{fd=1, revents=POLLOUT}]) write(1, "0000", 4) = 4 poll([{fd=0, events=POLLIN}], 1, 0) = 0 (Timeout) Git does not see that 0013status=success response though. It sees "0000", which must be the one that git-annex wrote earlier (top of above strace). So, this seems like a protocol problem of some kind. """]

— Wed Jul 13 21:17:50 2022

Add a comment