Created attachment 1183 [details] strace.27014.log Based on information from: http://lists.linuxtogo.org/pipermail/openembedded-core/2013-April/038496.html Today I got another hang in terminal which already had setup script sourced so it looks like this: bitbake@jama:~/build$ bitbake -c build my-image # and nothing else bitbake@jama:~$ ps auxf | grep my-image bitbake 28014 0.0 0.0 4400 704 pts/19 S+ 11:25 0:00 \_ /bin/sh /OE/build/oe-core/scripts/bitbake -c build my-image bitbake 28044 1.4 1.2 252592 201208 pts/19 S+ 11:25 0:02 | \_ python /OE/build/bitbake/bin/bitbake -c build my-image bitbake 28229 0.0 1.2 328424 199612 pts/19 Sl+ 11:25 0:00 | \_ python /OE/build/bitbake/bin/bitbake -c build my-image bitbake 28232 0.0 1.2 328424 198212 ? S 11:25 0:00 python /OE/build/bitbake/bin/bitbake -c build my-image no wget or git process running My previous report was a bit inaccurate about last python process, I said it got orphaned after first Ctrl+C, here it's orphan from the beginning. Before trying to kill it with Ctrl+C: jama ~ # strace -s 8912 -p 28014 2>&1 | tee strace.28014.log Process 28014 attached wait4(-1, jama ~ # strace -s 8912 -p 28044 2>&1 | tee strace.28044.log Process 28044 attached wait4(28229, jama ~ # strace -s 8912 -p 28229 2>&1 | tee strace.28229.log Process 28229 attached recvfrom(12, jama ~ # strace -s 8912 -p 28232 2>&1 | tee strace.28232.log Process 28232 attached futex(0xc57ea50, FUTEX_WAIT_PRIVATE, 0, NULL Ctrl+C shows SIGINT in first 2 processes, 3rd waits for futex now, no change in 4th (orphan) 3rd: recvfrom(12, 0xca0d7f4, 8192, 0, 0, 0) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL, si_value={int=12337, ptr=0x3031}} --- rt_sigreturn() = -1 EINTR (Interrupted system call) futex(0xc483890, FUTEX_WAIT_PRIVATE, 0, NULL Ctrl+C was repeated 3 times, SIGINT and FUTEX_WAIT is repated, but without any other change: bitbake@jama:~/build$ bitbake -c build my-image ^C^C^C bitbake@jama:~$ kill 28229 First 3 processes die (see attached strace logs) orphan still lives, his strace showing FUTEX: bitbake@jama:~$ ps auxf | grep my-image bitbake 28232 0.0 1.2 328424 198212 ? S 11:25 0:00 python /OE/build/bitbake/bin/bitbake -c build my-image bitbake@jama:~$ kill 28232 No new output in shell with bitbake: bitbake@jama:~/build$ bitbake -c build my-image ^C^C^C bitbake@jama:~/build$ All strace logs attached, I had to replace some product names from it (from LogRecord lines, so instead of product and machine name there is my-distro and my-device, build path was shortened to /OE/build because original also mentioned product). Sorry about that, I'll try to reproduce again with public layers only, but now I'm running much more builds with this private stuff included so the probability of hitting hang there is higher (but it's not limited to those layers, I have seen it with oe-core+meta-qt5 for sure and IIRC also with oe-core only too). Just after killing it: bitbake@jama:~/build$ bitbake -c build my-image NOTE: Started PRServer with DBfile: /OE/build/cache/prserv.sqlite3, IP: 127.0.0.1, PORT: 47180, PID: 3775 Loading cache: 100% |#########################################################################################################################| ETA: 00:00:00 Loaded 1847 entries from dependency cache. Parsing recipes: 100% |#######################################################################################################################| Time: 00:00:00 Parsing of 1481 .bb files complete (1480 cached, 1 parsed). 1846 targets, 104 skipped, 0 masked, 0 errors. WARNING: No bb files matched BBFILE_PATTERN_meta-qemux86-my-distro '^/OE/build/meta-qemux86-my-distro/' Build Configuration: BB_VERSION = "1.19.0" BUILD_SYS = "x86_64-linux" NATIVELSBSTRING = "Ubuntu-12.10" TARGET_SYS = "i586-my-distro-linux" MACHINE = "qemux86" DISTRO = "my-distro" DISTRO_VERSION = "0.5" TUNE_FEATURES = "m32 i586" TARGET_FPU = "" meta-my-distro = "owub5:fb273a7123b54651f6239a3dddb120e708a1fe47" meta-qemux86-my-distro = "owub5:87f635f501af5372c1e246d5e1e1d966763040fd" meta-my-device = "owub5:1ca4ae96bb73191d1afdac67e0fe35aacc708602" meta-my-layer = "owub5:7d6ab563a3f22cb6d354601ac1d2d83766bc7219" meta-webos = "owub5:9e8ad18bfd2e0ba76678bd71c4062ee21d1a0e42" meta-my-layer2 = "owub5:b3a63c74cc35d70fce02354a6ed0d5ac01aa595b" meta-oe meta-networking meta-ruby = "owub5:bea2397361da080df1256046b927b454e2e5fc9a" meta = "owub5:c49af6de052a45f05d948f61e207c9d168ee10b2" NOTE: Resolving any missing task queue dependencies and works fine..
Created attachment 1184 [details] strace.28044.log
Created attachment 1185 [details] strace.28299.log
Created attachment 1186 [details] strace.28232.log
Just reproduced with public layers only (and in different distribution - shr-chroot) OE om-gta02@shr ~/shr-core $ bitbake -c cleansstate llvm2.9; bitbake llvm2.9 NOTE: Started PRServer with DBfile: /OE/shr-core/cache/prserv.sqlite3, IP: 127.0.0.1, PORT: 58811, PID: 24603 Loading cache: 100% |#########################################################################################################################| ETA: 00:00:00 Loaded 2218 entries from dependency cache. Build Configuration: BB_VERSION = "1.19.0" BUILD_SYS = "x86_64-linux" NATIVELSBSTRING = "Gentoo-2.2" TARGET_SYS = "arm-oe-linux-gnueabi" MACHINE = "om-gta02" DISTRO = "shr" DISTRO_VERSION = "20130419" TUNE_FEATURES = "armv4 thumb" TARGET_FPU = "soft" meta-jama = "master:33e48de8cf588c9df80025339d7883e25a3e3fb8" meta-shr meta-aurora meta-fso meta-android = "webOS-ports/master:0fe4b5559335d24764260d47d3f60d68de502a61" meta-oe meta-efl meta-gnome meta-gpe meta-multimedia meta-networking meta-initramfs meta-systemd = "jansa/test:a5c0447694ddacab285f192e1d8e425f6899d6e3" meta-osmocombb meta-nokia meta-htc meta-palm meta-openmoko meta-samsung = "webOS-ports/master:0fe4b5559335d24764260d47d3f60d68de502a61" meta-browser = "jansa/test:359cdae903c3772796b4658dd3129742d9a76d05" meta-handheld = "jansa/spitz:68177884e36e08cb76f11048bdf8ee3435b75ea3" meta = "jansa/test:2ac95cf4581c963ae49bc6f7af430a05228c34bc" NOTE: Resolving any missing task queue dependencies NOTE: Preparing runqueue NOTE: Executing RunQueue Tasks NOTE: Tasks Summary: Attempted 2 tasks of which 0 didn't need to be rerun and all succeeded. # and nothing, here is 2nd bitbake started.. OE @ ~ $ ps auxf | grep llvm2.9 bitbake 2260 0.0 0.0 13832 1544 pts/16 S+ 12:57 0:00 | | \_ /bin/sh /OE/shr-core/openembedded-core/scripts/bitbake llvm2.9 bitbake 2449 0.3 2.8 553188 462116 pts/16 S+ 12:57 0:13 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 bitbake 8988 0.0 2.8 629020 459968 pts/16 Sl+ 12:58 0:00 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 bitbake 21880 0.0 0.0 8952 664 pts/4 S+ 14:09 0:00 | \_ grep --colour=auto llvm2.9 bitbake 9015 0.0 2.8 629020 458432 ? S 12:58 0:00 /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 #this time only one Ctrl+C and trying to kill orphan first OE @ ~ $ kill 9015 OE @ ~ $ ps auxf | grep llvm2.9 bitbake 2260 0.0 0.0 13832 1544 pts/16 S+ 12:57 0:00 | | \_ /bin/sh /OE/shr-core/openembedded-core/scripts/bitbake llvm2.9 bitbake 2449 0.2 2.8 553188 462116 pts/16 S+ 12:57 0:13 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 bitbake 8988 0.0 2.8 629020 459992 pts/16 Sl+ 12:58 0:00 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 bitbake 3329 0.0 0.0 8952 664 pts/4 S+ 14:14 0:00 | \_ grep --colour=auto llvm2.9 OE @ ~ $ kill 8988 OE @ ~ $ ps auxf | grep llvm2.9 bitbake 2260 0.0 0.0 13832 1544 pts/16 S+ 12:57 0:00 | | \_ /bin/sh /OE/shr-core/openembedded-core/scripts/bitbake llvm2.9 bitbake 2449 0.3 2.8 553156 462096 pts/16 R+ 12:57 0:14 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake llvm2.9 bitbake 14063 0.0 0.0 8952 664 pts/4 S+ 14:14 0:00 | \_ grep --colour=auto llvm2.9 OE @ ~ $ ps auxf | grep llvm2.9 bitbake 15496 0.0 0.0 8952 660 pts/4 S+ 14:14 0:00 | \_ grep --colour=auto llvm2.9 I'll attach all 4 straces again. All looks the same to me :/.
Created attachment 1188 [details] strace.2260.log
Created attachment 1189 [details] strace.2449.log
Created attachment 1190 [details] strace.8988.log
Created attachment 1191 [details] strace.9015.log
Tested with http://lists.linuxtogo.org/pipermail/bitbake-devel/2013-May/004335.html applied and hangs are still there
(In reply to comment #9) > Tested with > http://lists.linuxtogo.org/pipermail/bitbake-devel/2013-May/004335.html > applied and hangs are still there This doesn't surprise me, that was a particular corner case. What I'm currently trying to do is get bitbake working under python 3. It would be interesting to see if the issue is fixed there. I have a WIP patch: http://git.yoctoproject.org/cgit.cgi/poky-contrib/commit/?h=rpurdie/t1&id=97c2f48961bb04b1a7895a76d0d5aafa26dca645 however it won't let me complete builds yet. I'll continue to work on improving it. Its also possible some of the 2->3 cleanups may find a true bug... You might want to apply the try/except part of: http://git.yoctoproject.org/cgit.cgi/poky-contrib/diff/bitbake/bin/bitbake?h=rpurdie/t1&id=97c2f48961bb04b1a7895a76d0d5aafa26dca645 since that might at least give you console output when it crashes. Whether it does or not would be an interesting data point in itself. I will be applying a lot of these changes to master when I get a chance later this week to split them up and tidy them.
The try/except part I mentioned is now in master, would be good to know if this now hangs with any output or not...
(In reply to comment #11) > The try/except part I mentioned is now in master, would be good to know if > this now hangs with any output or not... I've reproduced this again today with bitbake: commit d0b180d868390a464b6799ad90db6bbe0350e158 Author: Richard Purdie <richard.purdie@linuxfoundation.org> Date: Thu May 9 21:19:04 2013 +0000 lib: print is a function in moderm python, covert remaining users It was in incremental build, just after -c cleansstate: OE om-gta02@shr ~/shr-core $ bitbake -c cleansstate libmpc-native; bitbake -c build libmpc-native NOTE: Started PRServer with DBfile: /OE/shr-core/cache/prserv.sqlite3, IP: 127.0.0.1, PORT: 42423, PID: 11628 Loading cache: 100% |#########################################################################################################################| ETA: 00:00:00 Loaded 2240 entries from dependency cache. Build Configuration: BB_VERSION = "1.19.0" BUILD_SYS = "x86_64-linux" NATIVELSBSTRING = "Gentoo-2.2" TARGET_SYS = "arm-oe-linux-gnueabi" MACHINE = "om-gta02" DISTRO = "shr" DISTRO_VERSION = "next-20130513" TUNE_FEATURES = "armv4 thumb" TARGET_FPU = "soft" meta-jama = "master:46fd98b460548be3ae8d57e1143f12194552d88d" meta-shr meta-aurora meta-fso meta-android = "jansa/test:0154e128d8f22ba8e61117c276775cc2088d92d7" meta-oe meta-efl meta-gnome meta-gpe meta-ruby meta-multimedia meta-networking meta-initramfs meta-systemd = "jansa/test:0221dd09c37202715385e48c723601fd26a2185e" meta-osmocombb meta-nokia meta-htc meta-palm meta-openmoko meta-samsung = "jansa/test:0154e128d8f22ba8e61117c276775cc2088d92d7" meta-browser = "jansa/test:ae5fa4b2a16771bd1d6adcde3eed00ca8cd366d4" meta-handheld = "jansa/spitz:5707911b5156be2544401133f73e2940db93b868" meta = "jansa/test:eb4bbd68e8845680ba115afa02cf92bdce7b1de3" NOTE: Resolving any missing task queue dependencies NOTE: Preparing runqueue NOTE: Executing RunQueue Tasks NOTE: Tasks Summary: Attempted 2 tasks of which 0 didn't need to be rerun and all succeeded. <and here it hangs for last 6 hours> OE @ ~ $ ps auxf | grep libmpc bitbake 12186 0.0 0.0 13832 1268 pts/2 S+ 17:31 0:00 | | \_ /bin/sh /OE/shr-core/openembedded-core/scripts/bitbake -c build libmpc-native bitbake 12208 0.0 1.7 406404 294488 pts/2 S+ 17:31 0:08 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c build libmpc-native bitbake 12242 0.0 1.7 482236 293656 pts/2 Sl+ 17:32 0:00 | | \_ /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c build libmpc-native bitbake 13367 0.0 0.0 9028 664 pts/20 S+ 23:55 0:00 | \_ grep --colour=auto libmpc bitbake 12245 0.0 1.7 482236 292312 ? S 17:32 0:00 /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c build libmpc-native Is there something possibly shared between multiple bitbake processes (running in different builddir and even from different bitbake checkout, but on same system e.g. same /dev/shm)? I think I see these hangs mostly when my system is under heavy load, but that's also usually caused by multiple builds running in parallel - I'll try to reproduce this idea by running some very short build but in many builddirs.
(In reply to comment #12) > NOTE: Resolving any missing task queue dependencies > NOTE: Preparing runqueue > NOTE: Executing RunQueue Tasks > NOTE: Tasks Summary: Attempted 2 tasks of which 0 didn't need to be rerun > and all succeeded. > <and here it hangs for last 6 hours> I'm not sure this is the same issue. In one case (as originally reported) Bitbake is hanging early in init with no output. The above build is hanging after much if the build as completed. This second issue is around the time buildhistory runs and may be related to that (I've seen builds pause here for a long time). I'd find it strange for the output patch to have added output if it was getting as far into task execution as this build appears so I think these could be two different issues.
(In reply to comment #13) > (In reply to comment #12) > > NOTE: Resolving any missing task queue dependencies > > NOTE: Preparing runqueue > > NOTE: Executing RunQueue Tasks > > NOTE: Tasks Summary: Attempted 2 tasks of which 0 didn't need to be rerun > > and all succeeded. > > <and here it hangs for last 6 hours> > > I'm not sure this is the same issue. In one case (as originally reported) > Bitbake is hanging early in init with no output. The above build is hanging > after much if the build as completed. This second issue is around the time > buildhistory runs and may be related to that (I've seen builds pause here > for a long time). > > I'd find it strange for the output patch to have added output if it was > getting as far into task execution as this build appears so I think these > could be two different issues. Sorry I've confused you with that output, it was running 2 commands, -c cleansstate (which finished fine) and then -c build which didn't show anything.
I've upgraded python from 2.7.4 to 2.7.5, but today I've seen this hang again. Again with multiple bitbake commands running in different BUILDDIRs (even different chroot environment) but sharing the same /dev/shm.
As another data point, we discovered a bug when we dropped pre python 2.7.3 support in that our multiprocessing pool workaround was always being used. There is a slim chance that now we require 2.7.3, the issue might be resolved...
Updated pstree with latest oe-core and bitbake: oe-core: commit 7950a307bc7d4104e6cfb09bb2ea267c5da83f2a Author: Saul Wold <sgw@linux.intel.com> Date: Wed Apr 3 09:08:38 2013 -0700 tcmode-default: Set GCC 4.8 as default bitbake: commit 3d8044bc79c482c5ea008ddf12a8128dcd1527ee Author: Richard Purdie <richard.purdie@linuxfoundation.org> Date: Fri Jun 21 11:31:32 2013 +0000 data_smart: Fix bug with overrides and weak default values OE @ ~/openembedded-core $ pstree -la | grep bzip2 |-bitbake /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native | | |-grep --colour=auto bzip2 | | `-bitbake /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native | | `-bitbake /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native OE @ ~/openembedded-core $ ps aux | grep bzip2 bitbake 16814 0.7 3.1 600972 513540 pts/14 S+ 11:48 0:13 /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native bitbake 17571 0.0 3.1 676804 511440 pts/14 Sl+ 11:48 0:00 /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native bitbake 17583 0.0 3.1 676804 509840 ? S 11:48 0:00 /usr/bin/python2.7 /OE/shr-core/bitbake/bin/bitbake -c cleansstate bzip2-native bitbake 24118 0.0 0.0 9048 664 pts/2 S+ 12:18 0:00 grep --colour=auto bzip2
Looks fixed by http://git.openembedded.org/bitbake/commit/?id=c5c8f33ca4b81877a0115887849881001b745bf0 http://git.openembedded.org/bitbake/commit/?id=8c01cff94787abbb64fbdf0c16cd63f8f97a7e03 http://git.openembedded.org/bitbake/commit/?id=972bc43e6d5b1207b944b3baa8f9805adb35dda7