diff options
Diffstat (limited to 'doc/bugs/git-annex_opens_too_many_files')
6 files changed, 214 insertions, 0 deletions
diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_1_37f6f5838c41c533df4be1f927b9b03d._comment b/doc/bugs/git-annex_opens_too_many_files/comment_1_37f6f5838c41c533df4be1f927b9b03d._comment new file mode 100644 index 000000000..de5dde9b5 --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_1_37f6f5838c41c533df4be1f927b9b03d._comment @@ -0,0 +1,26 @@ +[[!comment format=mdwn + username="chrisbra" + ip="80.149.220.45" + subject="sorry, added some wrapping signs from vim." + date="2013-08-06T18:01:40Z" + content=""" +[2013-08-06 13:32:51 CEST] main: starting assistant version 4.20130802-g1452ac3 + +Already up-to-date. +(scanning...) [2013-08-06 13:32:51 CEST] Watcher: Performing startup scan + +Already up-to-date. +(started...) +git-annex: accept: resource exhausted (Too many open files) +[2013-08-06 19:50:37 CEST] read: git [\"--git-dir=/home/christian/git-annex/.git\",\"--work-tree=/home/christian/git-annex\",\"symbolic-ref\",\"HEAD\"] +git-annex: runInteractiveProcess: pipe: Too many open files +[2013-08-06 19ND:ea5te1Wm:ao1tn1cS htCeaErtSFuTas]l lcNbreaatcsWkha etcdcr:ha es/rhh:eo dmd:ee /tgceihctrt:ie sdct rineaeantt/wegoPirrtko- cacenosnnsen:xe /cr.tegisiootnu/ +racnen[ e2ex0x/1h:3a -uo0sp8te-en0dT6 e (m1Tp9oF:oi5 l1me:a:1n 1yr eCosEpoSeuTnr] c feri eleaexdsh:)a +ugsitte d[ \"(-T-ogoi tm-adniyr =o/pheonm ef/iclhersi)s +tian/git-annex/.git\",\"--work-tree=/home/christian/git-annex\",\"symbolic-ref\",\"HEAD\"] +git-annex: runInteractiveProcess: pipe: Too many open files +git-annex: git: createProcess: resource exhausted (Too many open files) +[2013-08-06 19:51:11 CEST] NetWatcherFallback: warning NetWatcherFallback crashed: git: createProcess: resource exhausted (Too many open files) +[2013-08-06 19:51:11 CEST] DaemonStatus: warning DaemonStatus crashed: /home/christian/git-annex/.git/annex/: openTempFile: resource exhausted (Too many open files) + +"""]] diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_2_347ef233b9845b84d7c4d49ed166e797._comment b/doc/bugs/git-annex_opens_too_many_files/comment_2_347ef233b9845b84d7c4d49ed166e797._comment new file mode 100644 index 000000000..381d425fc --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_2_347ef233b9845b84d7c4d49ed166e797._comment @@ -0,0 +1,10 @@ +[[!comment format=mdwn + username="http://joeyh.name/" + ip="2001:4978:f:21a::2" + subject="comment 2" + date="2013-08-07T15:59:59Z" + content=""" +What operating system is this? + +Can you see which files the git-annex process has open? +"""]] diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_3_d5f644d97cd2db471deb5dcd728cae60._comment b/doc/bugs/git-annex_opens_too_many_files/comment_3_d5f644d97cd2db471deb5dcd728cae60._comment new file mode 100644 index 000000000..fbd3bce8f --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_3_d5f644d97cd2db471deb5dcd728cae60._comment @@ -0,0 +1,8 @@ +[[!comment format=mdwn + username="chrisbra" + ip="212.121.153.12" + subject="This is ubuntu 12.10" + date="2013-08-12T13:30:00Z" + content=""" +This is ubuntu 12.10 and seems to be the same problem which has been mentioned before (resource exhausted or similar) +"""]] diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_4_c03bde64be8fdd962826bc7afa07d2a9._comment b/doc/bugs/git-annex_opens_too_many_files/comment_4_c03bde64be8fdd962826bc7afa07d2a9._comment new file mode 100644 index 000000000..b4c458706 --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_4_c03bde64be8fdd962826bc7afa07d2a9._comment @@ -0,0 +1,137 @@ +[[!comment format=mdwn + username="https://www.google.com/accounts/o8/id?id=AItOawlmRpGORNKWimtzqItvwm4I6cn16vx8OvU" + nickname="hayden" + subject="Many network sockets with associated fds hanging around" + date="2013-08-15T18:00:42Z" + content=""" +I see something similar in logs and after roughly 10 mins the web-apps dies. +So I think I hit the same as the above user. +Sometimes I get thread deaths and restart requests but the root cause appears to match the scenario mentioned over. +Often the webapp just hangs. But always when it hits the fd ulimit... 1024 on this system. + +git-annex version is 4.20130802-g1452ac3 and I used the static-linked linux tar.gz linux-binary download. + +Test setup is a from scratch assistant startup on Ubuntu 12.04. +Not exactly a clean ubuntu though, so maybe difficult to duplicate troubles at your end. + +I fired up the web-app with a cleaned out config. No signs of leaks until an annex is created. +On creation of an empty annex I get fd leaks a about 1 per second after a repository is created. +Strace'ing the main process only shows 8-bytes writes (see below) at the same rate as the leak. +Sometimes the fd-leak stops before the resource limit, sometimes not. +Creating a new annex on top of an existing directory tree with many files is pretty reliable trigger though. +Startup scan finishes and fds leak away until the ulimit is hit. + + hayden@orca:~/gamma$ ls /proc/26319/fd + 0 10 12 14 16 18 2 21 23 25 27 29 30 32 34 36 38 4 41 43 45 6 8 + 1 11 13 15 17 19 20 22 24 26 28 3 31 33 35 37 39 40 42 44 5 7 9 + hayden@orca:~/gamma$ ls /proc/26319/fd + 0 10 12 14 16 18 2 21 23 25 27 29 30 32 34 36 38 4 41 43 45 6 8 + 1 11 13 15 17 19 20 22 24 26 28 3 31 33 35 37 39 40 42 44 5 7 9 + hayden@orca:~/gamma$ ls /proc/26319/fd + 0 10 12 14 16 18 2 21 23 25 27 29 30 32 34 36 38 4 41 43 45 5 7 9 + 1 11 13 15 17 19 20 22 24 26 28 3 31 33 35 37 39 40 42 44 46 6 8 + + hayden@orca:~/gamma$ ls /proc/26319/fd/43 + /proc/26319/fd/43 + + hayden@orca:~/gamma$ ls -l /proc/26319/fd/43 + ls -l /proc/26319/fd/43 + lrwx------ 1 hayden hayden 64 Aug 14 21:10 /proc/26319/fd/43 -> socket:[568994] + + hayden@orca:~/gamma$ lsof | grep 568994 + git-annex 26319 hayden 43u IPv4 568994 0t0 UDP 224.0.0.251:55556 + + hayden@orca:~/gamma$ uname -a + Linux orca 3.2.0-25-generic #40-Ubuntu SMP Wed May 23 20:30:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux + + hayden@orca:~/gamma$ cat /etc/issue + Ubuntu 12.04 LTS \n \l + + hayden@orca:~/gamma$ fuser 55556/udp -a + 55556/udp: 4415 26319 27080 27083 + + hayden@orca:~/gamma$ ps aux | grep 4415 + hayden 4415 0.0 0.0 66716 3036 ? S Aug12 0:03 curl -s --head -L http://127.0.0.1:38464/?auth=da9c4aba4cc2db9cf78574753f6e94d8031c6a7bdf8bfe100bde868f57b81fd751965cc9d68a9afac79f826d257a256a04ce62615a7f23cd7c925969dda1c7b8 -w %{http_code} + hayden 27458 0.0 0.0 10612 924 pts/0 S+ 21:50 0:00 grep --color=auto 4415 + + hayden@orca:~/gamma$ ps aux | grep 26319 + hayden 26319 0.1 0.7 497188 28560 pts/5 Sl 21:09 0:04 git-annex webapp + hayden 26338 3.4 3.4 1035572 137864 pts/5 Sl 21:09 1:25 /usr/lib/firefox/firefox /tmp/webapp26319.html + hayden 27460 0.0 0.0 10612 920 pts/0 S+ 21:50 0:00 grep --color=auto 26319 + + hayden@orca:~/gamma$ ps aux | grep 27080 + hayden 27080 0.0 0.0 16476 1288 pts/5 S 21:33 0:00 git --git-dir=/home/hayden/boo/.git --work-tree=/home/hayden/boo cat-file --batch + hayden 27462 0.0 0.0 10612 924 pts/0 S+ 21:50 0:00 grep --color=auto 27080 + + hayden@orca:~/gamma$ ps aux | grep 27083 + hayden 27083 0.0 0.0 16476 1060 pts/5 S 21:33 0:00 git --git-dir=/home/hayden/boo/.git --work-tree=/home/hayden/boo check-attr -z --stdin annex.backend annex.numcopies -- + hayden 27464 0.0 0.0 10612 920 pts/0 S+ 21:51 0:00 grep --color=auto 27083 + +----> has 579 open fds at this point but this number holds stable over 10 min +(copy in new tree to provoke) +(no change) +----> restart daemon in gui to provoke +(new process has open fds slowly climbing after startup scan) + +straces look like this repeating every second. (clipped down) + + futex(0x34f001c, FUTEX_WAIT_PRIVATE, 51, NULL) = ? ERESTARTSYS (To be restarted) + --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- + rt_sigreturn(0x1a) = 202 + futex(0x34f001c, FUTEX_WAIT_PRIVATE, 51, NULL) = ? ERESTARTSYS (To be restarted) + --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- + rt_sigreturn(0x1a) = 202 + futex(0x34f001c, FUTEX_WAIT_PRIVATE, 51, NULL) = ? ERESTARTSYS (To be restarted) + --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- + rt_sigreturn(0x1a) = 202 + futex(0x34f001c, FUTEX_WAIT_PRIVATE, 51, NULL) = ? ERESTARTSYS (To be restarted) + --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- + write(6, \"\377\0\0\0\0\0\0\0\", 8) = 8 + rt_sigreturn(0x2) = 202 + futex(0x34f001c, FUTEX_WAIT_PRIVATE, 51, NULL^C <unfinished ...> + Process 29803 detached + +Until after roughly 10 mins... + + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1017 + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1023 + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1024 + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1024 + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1024 + hayden@orca:~/boo$ ls /proc/29803/fd | wc -l + 1024 + + hayden@orca:~/boo$ ulimit -a + core file size (blocks, -c) 0 + data seg size (kbytes, -d) unlimited + scheduling priority (-e) 0 + file size (blocks, -f) unlimited + pending signals (-i) 31164 + max locked memory (kbytes, -l) 64 + max memory size (kbytes, -m) unlimited + open files (-n) 1024 + pipe size (512 bytes, -p) 8 + POSIX message queues (bytes, -q) 819200 + real-time priority (-r) 0 + stack size (kbytes, -s) 8192 + cpu time (seconds, -t) unlimited + max user processes (-u) 31164 + virtual memory (kbytes, -v) unlimited + file locks (-x) unlimited + hayden@orca:~/boo$ + +At this point the webapp hangs but a number of interesting crashes may occur. I've also seen the particular error in the previous users log (on a big tree). + + [2013-08-14 21:56:12 CEST] main: starting assistant version 4.20130802-g1452ac3 + (scanning...) [2013-08-14 21:56:12 CEST] Watcher: Performing startup scan + (started...) DaemonStatus crashed: /home/hayden/boo/.git/annex/: openTempFile: resource exhausted (Too many open files) + [2013-08-14 22:06:12 CEST] DaemonStatus: warning DaemonStatus crashed: /home/hayden/boo/.git/annex/: openTempFile: resource exhausted (Too many open files) + +Is any of the above helpful? Anything else useful to kick for testing that you'd like done? +I'd guess this is something weird with my ubuntu setup that provokes this as more users would see it otherwise. +"""]] diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_5_33a2e783e5355e981497b9861997570b._comment b/doc/bugs/git-annex_opens_too_many_files/comment_5_33a2e783e5355e981497b9861997570b._comment new file mode 100644 index 000000000..786672eb2 --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_5_33a2e783e5355e981497b9861997570b._comment @@ -0,0 +1,18 @@ +[[!comment format=mdwn + username="http://joeyh.name/" + ip="4.154.0.63" + subject="comment 5" + date="2013-08-24T17:09:43Z" + content=""" +Thanks for an excellent amount of debug information. + +I can see what's leaking is UDP connections to 224.0.0.251. That address is used for the \"local pairing\" option in the webapp. + +I was able to reproduce the problem by disabling all network interfaces except `lo`. The PairListener then failed to open a multicast listening socket. When it fails that way, it retried every second, as you noticed. And there is a socket leak in that failure mode. + +I wonder if you're seeing this even when on the network? If so, perhaps your Ubuntu system has something going on that prevents opening a multicast listening socket on even `eth0` or `wlan0` or whatever. + +Unfortunately, the actual socket leak bug is in the [network-multicast](http://hackage.haskell.org/package/network-multicast) library, and not in git-annex. I have filed an upstream bug report: <https://github.com/audreyt/network-multicast/issues/4> + +Hopefully that will be dealt with soon. There is a workaround I could do in git-annex: If it fails (leaking one socket), it could wait until the NetworkListener indicated a new network interface was opened, before trying again (possibly leaking one socket again). This would change it from a 1 per second leak to a 1 per change of network leak at worst, which is probably much less likely to cause problems. +"""]] diff --git a/doc/bugs/git-annex_opens_too_many_files/comment_6_b3a5a4e4ca29c5cd2840bfeb4c63ea68._comment b/doc/bugs/git-annex_opens_too_many_files/comment_6_b3a5a4e4ca29c5cd2840bfeb4c63ea68._comment new file mode 100644 index 000000000..60c268fc0 --- /dev/null +++ b/doc/bugs/git-annex_opens_too_many_files/comment_6_b3a5a4e4ca29c5cd2840bfeb4c63ea68._comment @@ -0,0 +1,15 @@ +[[!comment format=mdwn + username="http://joeyh.name/" + ip="4.154.0.63" + subject="comment 6" + date="2013-08-24T18:38:56Z" + content=""" +My NetListener workaround turned out to not be portable enough. + +However, I have sent a patch to fix the FD leak: <https://github.com/audreyt/network-multicast/pull/6> +Hopefully it gets applied soon. + +I have also made the PairListener only retry every 60 seconds. Which makes the leak 1/60th as bad, for whatever that's worth. + +Once a fix for this gets into Debian, I need to remember to backport it to stable, and update the autobuilders to use it. Also need to remember to update the Android autobuilder. Leaving this bug report open until that happens. +"""]] |