I was running full system upgrade after quite a lot of time (~6 months) and it hung upon emerging openmotif. This process uses 100% cpu and takes for ever (well, at least 12 hours). /var/tmp/portage/x11-libs/openmotif-2.3.3/work/openmotif-2.3.3/tools/wml/.libs/wmldbcreate -o motif.wmd When I SIGTERM portage, everything keeps running (see additional information). If I attach strace to it, strace shows nothing and hangs, and the only way to kill strace is SIGKILL. Another interesting thing: stopas:/var/tmp/portage/x11-libs/openmotif-2.3.3/work/openmotif-2.3.3/tools# ls Imakefile Makefile Makefile.am Makefile.in wml stopas:/var/tmp/portage/x11-libs/openmotif-2.3.3/work/openmotif-2.3.3/tools# ls wml <takes for ever> Reproducible: Always Steps to Reproduce: 1. emerge x11-libs/openmotif=2.3.3 Actual Results: The process takes for ever what ever I do. Expected Results: Openmotif emerges stopas:/home/motiejus-gentoo# uname -a && lsb_release -d && btrfs files df / Linux stopas 2.6.37-gentoo #2 SMP Tue Feb 1 18:33:05 GMT 2011 i686 Intel(R) Core(TM)2 Duo CPU T7250 @ 2.00GHz GenuineIntel GNU/Linux Description: Gentoo Base System release 2.0.1 Data: total=72.00GB, used=68.81GB System, DUP: total=8.00MB, used=28.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=7.38GB, used=1.69GB stopas:/home/motiejus-gentoo# # ps axjf | grep -B13 motif.wmd 6961 6993 6874 6739 tty1 6852 Sl 1000 0:18 \_ /usr/lib/xulrunner-1.9.2/plugin-container /opt/Adobe/flash-player/libflashplayer.so 6961 plugin 1 6967 6892 6892 ? -1 S 1000 0:00 /usr/libexec/gconfd-2 1 19375 6822 6798 pts/0 27353 S 0 0:00 [x11-libs/openmotif-2.3.3] sandbox "/usr/lib/portage/bin/ebuild.sh" compile 19375 19376 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/bash /usr/lib/portage/bin/ebuild.sh compile 19376 19407 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/bash /usr/lib/portage/bin/ebuild.sh compile 19407 19414 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/bash /usr/lib/portage/bin/ebuild-helpers/emake -j1 MWMRCDIR=/etc/X11/mwm 19414 19419 6822 6798 pts/0 27353 S 0 0:00 \_ make -j3 -s -j1 MWMRCDIR=/etc/X11/mwm 19419 19420 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/sh -c fail= failcom='exit 1'; \?for f in x $MAKEFLAGS; do \? case $f in \? *=* | --[!k]*);; \? *k*) failcom='fail=yes';; \? esac; \?done; \?dot_seen=no; \?target=`echo all-recursive | sed s/-recursive//`; \?list='bindings bitmaps config localized lib include tools clients doc'; for subdir in $list; do \? echo "Making $target in $subdir"; \? if test "$subdir" = "."; then \? dot_seen=yes; \? local_target="$target-am"; \? else \? local_target="$target"; \? fi; \? (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \? || eval $failcom; \?done; \?if test "$dot_seen" = "no"; then \? make "$target-am" || exit 1; \?fi; test -z "$fail" 19420 26473 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/sh -c fail= failcom='exit 1'; \?for f in x $MAKEFLAGS; do \? case $f in \? *=* | --[!k]*);; \? *k*) failcom='fail=yes';; \? esac; \?done; \?dot_seen=no; \?target=`echo all-recursive | sed s/-recursive//`; \?list='bindings bitmaps config localized lib include tools clients doc'; for subdir in $list; do \? echo "Making $target in $subdir"; \? if test "$subdir" = "."; then \? dot_seen=yes; \? local_target="$target-am"; \? else \? local_target="$target"; \? fi; \? (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \? || eval $failcom; \?done; \?if test "$dot_seen" = "no"; then \? make "$target-am" || exit 1; \?fi; test -z "$fail" 26473 26474 6822 6798 pts/0 27353 S 0 0:00 \_ make all 26474 26475 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/sh -c fail= failcom='exit 1'; \?for f in x $MAKEFLAGS; do \? case $f in \? *=* | --[!k]*);; \? *k*) failcom='fail=yes';; \? esac; \?done; \?dot_seen=no; \?target=`echo all-recursive | sed s/-recursive//`; \?list='wml'; for subdir in $list; do \? echo "Making $target in $subdir"; \? if test "$subdir" = "."; then \? dot_seen=yes; \? local_target="$target-am"; \? else \? local_target="$target"; \? fi; \? (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \? || eval $failcom; \?done; \?if test "$dot_seen" = "no"; then \? make "$target-am" || exit 1; \?fi; test -z "$fail" 26475 26479 6822 6798 pts/0 27353 S 0 0:00 \_ /bin/sh -c fail= failcom='exit 1'; \?for f in x $MAKEFLAGS; do \? case $f in \? *=* | --[!k]*);; \? *k*) failcom='fail=yes';; \? esac; \?done; \?dot_seen=no; \?target=`echo all-recursive | sed s/-recursive//`; \?list='wml'; for subdir in $list; do \? echo "Making $target in $subdir"; \? if test "$subdir" = "."; then \? dot_seen=yes; \? local_target="$target-am"; \? else \? local_target="$target"; \? fi; \? (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \? || eval $failcom; \?done; \?if test "$dot_seen" = "no"; then \? make "$target-am" || exit 1; \?fi; test -z "$fail" 26479 26480 6822 6798 pts/0 27353 D 0 0:00 \_ make all 26480 26909 6822 6798 pts/0 27353 R 0 13:59 \_ /var/tmp/portage/x11-libs/openmotif-2.3.3/work/openmotif-2.3.3/tools/wml/.libs/wmldbcreate -o motif.wmd ---------------------------- end of ps ajxf stopas:/home/motiejus-gentoo# strace strace -p 26909 execve("/usr/bin/strace", ["strace", "-p", "26909"], [/* 23 vars */]) = 0 brk(0) = 0x96ff000 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb78a0000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=140577, ...}) = 0 mmap2(NULL, 140577, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb787d000 close(3) = 0 open("/lib/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\20m\1\0004\0\0\0"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0755, st_size=1323292, ...}) = 0 mmap2(NULL, 1333544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7737000 mmap2(0xb7877000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13f) = 0xb7877000 mmap2(0xb787a000, 10536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb787a000 close(3) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7736000 set_thread_area({entry_number:-1 -> 6, base_addr:0xb77366c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0 mprotect(0xb7877000, 8192, PROT_READ) = 0 mprotect(0x807b000, 4096, PROT_READ) = 0 mprotect(0xb78be000, 4096, PROT_READ) = 0 munmap(0xb787d000, 140577) = 0 brk(0) = 0x96ff000 brk(0x9720000) = 0x9720000 getpid() = 27583 getuid32() = 0 getgid32() = 0 rt_sigaction(SIGTTOU, {SIG_IGN, [], 0}, NULL, 8) = 0 rt_sigaction(SIGTTIN, {SIG_IGN, [], 0}, NULL, 8) = 0 rt_sigaction(SIGHUP, {0x8049ad0, [], 0}, NULL, 8) = 0 rt_sigaction(SIGINT, {0x8049ad0, [], 0}, NULL, 8) = 0 rt_sigaction(SIGQUIT, {0x8049ad0, [], 0}, NULL, 8) = 0 rt_sigaction(SIGPIPE, {0x8049ad0, [], 0}, NULL, 8) = 0 rt_sigaction(SIGTERM, {0x8049ad0, [], 0}, NULL, 8) = 0 rt_sigaction(SIGCHLD, {SIG_DFL, [], 0}, NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT PIPE TERM], NULL, 8) = 0 ptrace(PTRACE_ATTACH, 26909, 0x1, 0) = 0 write(2, "Process 26909 attached - interru"..., 43Process 26909 attached - interrupt to quit ) = 43 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 wait4(-1, <hung up here>
Created attachment 261923 [details] emerge --info
After reboot I tried to run the same command manually. See the attachment for full strace (>16KB). When I git ctrl-c, strace exits, but the program keeps running: PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command 6964 root 20 0 6884 1316 984 R 99.0 0.1 2:36.19 ./wmldbcreate -o motif.wmd Thanks!
Created attachment 261925 [details] strace ./wmldbcreate -o motif.wmd
What if you experimentally shifted PORTAGE_TMPDIR to a non-btrfs filesystem?
Switching to ext2 worked. That's scary. Whom should I report it further?
(In reply to comment #5) > Switching to ext2 worked. That's scary. > > Whom should I report it further? Good question. Reassigning to kernel.
After hanging can you try alt-sysrq-w, and then the dmesg output, which might contain a backtrace for every blocked process
[ 733.358005] SysRq : Show Blocked State [ 733.358005] task PC stack pid father [ 733.358005] firefox D c9cae300 0 7328 1 0x00000000 [ 733.358005] f4455e0c 00200086 f5834200 c9cae300 c16f5e40 f57e2be0 c16f5e40 f57e2e5c [ 733.358005] f57e2e58 f57e2e58 c16f5e40 c16f5e40 bdcec258 000000aa bdce30ca 000000aa [ 733.358005] f57e2be0 c142f42a bd0f12f9 01002191 b2a1db27 f4455ddc c104acc3 f5643378 [ 733.358005] Call Trace: [ 733.358005] [<c142f42a>] ? schedule+0x627/0x666 [ 733.358005] [<c104acc3>] ? timekeeping_get_ns+0x11/0x4f [ 733.358005] [<c104b862>] ? ktime_get_ts+0x89/0x93 [ 733.358005] [<c142f499>] io_schedule+0x30/0x47 [ 733.358005] [<c10ce093>] sync_buffer+0x33/0x37 [ 733.358005] [<c142f8f4>] __wait_on_bit+0x34/0x5b [ 733.358005] [<c10ce060>] ? sync_buffer+0x0/0x37 [ 733.358005] [<c10ce060>] ? sync_buffer+0x0/0x37 [ 733.358005] [<c142f9b6>] out_of_line_wait_on_bit+0x9b/0xa3 [ 733.358005] [<c1044118>] ? wake_bit_function+0x0/0x37 [ 733.358005] [<c10ce002>] __wait_on_buffer+0x1b/0x1e [ 733.358005] [<c112ebe3>] write_dev_supers+0x137/0x217 [ 733.358005] [<c112ee97>] write_all_supers+0x1d4/0x220 [ 733.358005] [<c112eeef>] write_ctree_super+0xc/0xe [ 733.358005] [<c11596e6>] btrfs_sync_log+0x36c/0x40f [ 733.358005] [<c113d66d>] btrfs_sync_file+0x10e/0x14a [ 733.358005] [<c10cbd5b>] vfs_fsync_range+0x3f/0x61 [ 733.358005] [<c10cbdf6>] vfs_fsync+0x14/0x16 [ 733.358005] [<c10cbe1b>] do_fsync+0x23/0x33 [ 733.358005] [<c10cbe3b>] sys_fdatasync+0x10/0x12 [ 733.358005] [<c100288c>] sysenter_do_call+0x12/0x22 [ 733.358005] updatedb D 00000000 0 7588 7581 0x00000000 [ 733.358005] f2847b54 00000082 00000000 00000000 c16f5e40 f53cebe0 c16f5e40 f53cee5c [ 733.358005] f53cee58 f53cee58 c16f5e40 c16f5e40 bf78e54e 000000aa bf768beb 000000aa [ 733.358005] f53cebe0 b6760000 00000025 f2847b4c b2a1db27 f2847b24 c104acc3 f5643cd8 [ 733.358005] Call Trace: [ 733.358005] [<c104acc3>] ? timekeeping_get_ns+0x11/0x4f [ 733.358005] [<c104b862>] ? ktime_get_ts+0x89/0x93 [ 733.358005] [<c142f499>] io_schedule+0x30/0x47 [ 733.358005] [<c1087e69>] sync_page+0x3c/0x40 [ 733.358005] [<c142f8f4>] __wait_on_bit+0x34/0x5b [ 733.358005] [<c1087e2d>] ? sync_page+0x0/0x40 [ 733.358005] [<c1088052>] wait_on_page_bit+0x7b/0x84 [ 733.358005] [<c1044118>] ? wake_bit_function+0x0/0x37 [ 733.358005] [<c114cc39>] read_extent_buffer_pages+0x205/0x248 [ 733.358005] [<c112d48e>] btree_read_extent_buffer_pages+0x3b/0x8e [ 733.358005] [<c112d55d>] ? btree_get_extent+0x0/0x195 [ 733.358005] [<c112dd3f>] read_tree_block+0x29/0x3e [ 733.358005] [<c111a6dc>] read_block_for_search+0x2b4/0x2e2 [ 733.358005] [<c111ab42>] ? bin_search+0x39/0x44 [ 733.358005] [<c111ea34>] btrfs_search_slot+0x32d/0x457 [ 733.358005] [<c1177694>] ? selinux_inode_alloc_security+0x29/0x6e [ 733.358005] [<c112cb34>] btrfs_lookup_inode+0x28/0x84 [ 733.358005] [<c111c4f2>] ? btrfs_alloc_path+0x12/0x1f [ 733.358005] [<c111c4f2>] ? btrfs_alloc_path+0x12/0x1f [ 733.358005] [<c1138e4c>] btrfs_iget+0xa8/0x39d [ 733.358005] [<c113b407>] btrfs_lookup_dentry+0xdc/0x34c [ 733.358005] [<c113b682>] btrfs_lookup+0xb/0x22 [ 733.358005] [<c10b83e6>] d_alloc_and_lookup+0x3f/0x56 [ 733.358005] [<c10b84cb>] do_lookup+0x94/0xcb [ 733.358005] [<c10b9677>] link_path_walk+0x31d/0x444 [ 733.358005] [<c1175479>] ? dentry_has_perm+0x42/0x4a [ 733.358005] [<c10b9a4b>] path_walk+0x3a/0x84 [ 733.358005] [<c10b8776>] ? path_init+0x95/0x102 [ 733.358005] [<c10b9ab6>] do_path_lookup+0x21/0x6f [ 733.358005] [<c10bad4d>] user_path_at+0x39/0x5f [ 733.358005] [<c10b4518>] vfs_fstatat+0x2d/0x54 [ 733.358005] [<c10b4583>] vfs_lstat+0x16/0x18 [ 733.358005] [<c10b4599>] sys_lstat64+0x14/0x28 [ 733.358005] [<c100288c>] sysenter_do_call+0x12/0x22 motiejus@stopas:~$
this is being discussed on the linux-btrfs upstream mailing list. Hopefully, a fix comes out soon.
There are some new patches concerning enospc in rc7. Can you test with git-sources-2.6.38-rc7 ?
Checked with 2.6.38 from portage. Installation went successfully. Thank you.
*** Bug 368441 has been marked as a duplicate of this bug. ***