Created attachment 2238 [details] Sample of strace activity Hello, I have reproducible problem with dizzy. It happens like this: I run "bitbake core-image-sato --continue". Then one package build fails somewhere in the configuration phase. After that, I press Ctrl-C once and I see the usual Keyboard Interrupt, closing down... message but after the last step has finished, bitbake doesn't exit. I see one process hanging, eating 100% of one core and not responding to any signal anymore. The problem apparently doesn't occur when no package build failed before, then it sanely responds to Ctrl-C and gracefully exits after finishing the last active step.
I tried to reproduce this and couldn't. When you say "one package build fails somewhere in the configuration phase" you mean a do_configure task failed? The console logs would be helpful to double check I'm trying the right things to reproduce this.
Now that's getting weird. I tried to reproduce again and I run into https://bugzilla.yoctoproject.org/show_bug.cgi?id=6974 but I also get a failed package (opkg). When I press Ctrl-C I end up in the mentioned situation (python process is looping, now with only ~ 35 percent CPU time) and I also see lots of stopped processes that belonged to the now hung do_compile step of the linux_3.4 recipe (from meta-sunxi). xuser 6479 9.0 0.2 87016 36832 pts/2 S+ 00:34 2:24 | \_ python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6481 35.0 2.3 612232 286504 pts/2 Rl+ 00:34 9:19 | \_ python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6645 0.0 0.7 120240 88076 pts/2 S+ 00:35 0:01 | \_ python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake-worker decafbad xuser 7157 0.0 0.7 122600 87212 pts/2 T 00:36 0:00 | \_ python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake-worker decafbad xuser 7158 0.0 0.0 11732 2316 pts/2 T 00:36 0:00 | \_ /bin/sh /mnt/exroot/work/yocto/poky/build-a20/tmp/work/olinuxino_a20-poky-linux-gnueabi/linux/3.4.90-r1/temp/run.do_compile xuser 7159 0.0 0.0 7520 2740 pts/2 T 00:36 0:00 | \_ make -j4 uImage CC=arm-poky-linux-gnueabi-gcc -mno-thumb-interwork -marm LD=arm-poky-linux-gnueabi-ld.bfd (more T state child processes) DISTRO_VERSION = "1.7" TUNE_FEATURES = "arm armv7a vfp neon callconvention-hard vfpv4 cortexa7" TARGET_FPU = "vfp-vfpv4-neon" meta meta-yocto meta-yocto-bsp = "dizzy:9e8bb322154e67e521e8c982d20d46dda20c024b" meta-mono = "master:802138721cc72e5f4fb9853b0552a117e677536e" meta-qt5 = "dizzy:0732e184acef5e0200f46d7f95702774e5de1904" meta-sunxi = "dizzy:0ed1eadb956158471748878a8df4bfcf979184f5" meta-alt-desktop-extras = "master:620662faae71971c4c976d3556b3a88e83915c07" meta-oe meta-gnome meta-multimedia meta-filesystems meta-networking meta-python = "dizzy:9efaed99125b1c4324663d9a1b2d3319c74e7278" NOTE: Preparing runqueue WARNING: Unable to get checksum for opkg-config-base SRC_URI entry local-feeds.conf: [Errno 2] No such file or directory: '/mnt/exroot/work/yocto/poky/build-a20/downloads/local-feeds.conf' NOTE: Executing SetScene Tasks NOTE: Executing RunQueue Tasks WARNING: Failed to fetch URL file://local-feeds.conf, attempting MIRRORS if available ERROR: Fetcher failure: Unable to find file file://local-feeds.conf anywhere. The paths that were searched were: /mnt/exroot/work/yocto/poky/meta-alt-desktop-extras/recipes-devtools/opkg/opkg-config-base/poky /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base-1.0/poky /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base/poky /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/files/poky /mnt/exroot/work/yocto/poky/meta-alt-desktop-extras/recipes-devtools/opkg/opkg-config-base/olinuxino-a20 /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base-1.0/olinuxino-a20 /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base/olinuxino-a20 /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/files/olinuxino-a20 /mnt/exroot/work/yocto/poky/meta-alt-desktop-extras/recipes-devtools/opkg/opkg-config-base/armv7a /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base-1.0/armv7a /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base/armv7a /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/files/armv7a /mnt/exroot/work/yocto/poky/meta-alt-desktop-extras/recipes-devtools/opkg/opkg-config-base/arm /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base-1.0/arm /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base/arm /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/files/arm /mnt/exroot/work/yocto/poky/meta-alt-desktop-extras/recipes-devtools/opkg/opkg-config-base/ /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base-1.0/ /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base/ /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/files/ /mnt/exroot/work/yocto/poky/build-a20/downloads ERROR: Function failed: Fetcher failure for URL: 'file://local-feeds.conf'. Unable to fetch URL from any source. ERROR: Logfile of failure stored in: /mnt/exroot/work/yocto/poky/build-a20/tmp/work/olinuxino_a20-poky-linux-gnueabi/opkg-config-base/1.0-r1/temp/log.do_fetch.6665 ERROR: Task 1362 (/mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base_1.0.bb, do_fetch) failed with exit code '1' Keyboard Interrupt, closing down... Waiting for 1 running tasks to finish: 0: linux-3.4.90-r1 do_compile (pid 7157) (frozen, never finished) $ strace -f -p 6481 (will be attached)
Created attachment 2272 [details] Different pattern of hanging python process
I created a dummy SRC_URI in opkg-config-base and tried to reproduce this and in my case, the system exits normally. In order to try and reproduce this I have some further questions: a) What value of BB_NUMBER_THREADS and PARALLEL_MAKE is in use? b) What kind of terminal environment is this being run in? Over ssh? tmux? screen? c) Which distro is this being run on? d) Can you confirm you just press Ctrl+C once? (I'm pretty sure from the report you do but I'd like to double check). e) Are you using any other configuration which would involve other processes (e.g. PR server, toaster)? The reason I ask is that as far as I can tell, the Ctrl+C signal seems to be being passed to the child processes. I say that since its the only way I can see the unrelated jobs ending up in the T state. Normally, the UI should receive the signal and it should not be passed to anything else. The question is therefore whether some kind of unexpected signal handling is going on and if so, why/how. As yet I've been unable to reproduce this failure or the one in the other bug report.
I have some theories about this, the main thing I don't understand is why you're seeing this and I'm not. We do need to understand what the environment difference is there to fully fix this. What you could try is replacing the os.setpgid(0,0) line in bitbake/bin/bitbake-worker with os.setsid(). That should ensure all children are not attached to the controlling terminal so even if the signal masks get messed up, they will not recieve the Ctrl+C signal. If that helps, we still need to understand then environment difference but do have some idea what is happening.
Created attachment 2275 [details] build solution's config To a) here is my local.conf, as you see it's the BB and MAKE thread number is 4. b) yeah, it's a "screen" in an rxvt-unicode in regular X11 environment, icewm. Is there a problem with this? I've used screen a lot with Yocto 1.5 and have not seen anything like this before. c) Debian Unstable, (i.e. Jessie plus X), $ lsb_release -a No LSB modules are available. Distributor ID: Debian Description: Debian GNU/Linux 8.0 (jessie) Release: 8.0 Codename: jessie $ uname -a Linux zombie 3.18.0-rc6+ #3 SMP PREEMPT Sat Nov 29 21:03:44 CET 2014 x86_64 GNU/Linux $ grep model.name /proc/cpuinfo model name : AMD Phenom(tm) II X4 955 Processor ... d) I press Ctrl-C once and I get the situation described yesterday (one python task is looping with some stat/statfs syscalls inbetween and about 35 percent CPU consumption, and lots of processes in halted state). When I press it again (which usually would invoke the process killer) then I get the situation that I initially described: Second Keyboard Interrupt, stopping... Summary: 1 task failed: /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base_1.0.bb, do_fetch Summary: There were 4 WARNING messages shown. Summary: There were 2 ERROR messages shown, returning a non-zero exit code. Execution was interrupted, returning a non-zero exit code. NOTE: Sending SIGTERM to remaining 1 tasks and now it's really hung and I see a python process consuming 99 percent of a core and top displays one python task looping on one core: 6481 xuser 20 0 612232 286504 4484 R 100,4 2,3 104:46.97 python and strace shows that it doing read/write all the time, and $ ps -eLf | grep 6481 xuser 6481 6479 6481 9 4 00:34 pts/2 01:09:35 python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6481 6479 6482 4 4 00:34 pts/2 00:36:56 python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6481 6479 6510 0 4 00:35 pts/2 00:00:00 python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6481 6479 6511 0 4 00:35 pts/2 00:00:00 python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake -k core-image-sato xuser 6645 6481 6645 0 1 00:35 pts/2 00:00:01 python /mnt/exroot/work/yocto/poky/bitbake/bin/bitbake-worker decafbad ... and the fd of this read/writes is some domain socket: 12u unix 0xffff8802d3377100 0t0 17313985 socket e) not using toaster. I started experimenting with Yocto 1.6 and 1.7 a couple of weeks ago and am running into wild issues like this and also https://bugzilla.yoctoproject.org/show_bug.cgi?id=6974 (as said, they might be related). In fact, I remember having tried toaster once for fun and this was the only single run where I succeeded to build an image for sunxi (linuxino). I think I will try that again now.
PS: I mean read/wait, not read/write, like this: [pid 6481] read(22, 0x83ec444, 102400) = -1 EAGAIN (Resource temporarily unavailable) [pid 6481] wait4(6645, 0x7fff59fc2644, WNOHANG, NULL) = 0 [pid 6481] wait4(6645, 0x7fff59fc2504, WNOHANG, NULL) = 0 [pid 6481] read(22, 0x83ec444, 102400) = -1 EAGAIN (Resource temporarily unavailable) [pid 6481] wait4(6645, 0x7fff59fc2644, WNOHANG, NULL) = 0 [pid 6481] wait4(6645, 0x7fff59fc2504, WNOHANG, NULL) = 0
(In reply to comment #6) > Created attachment 2275 [details] > build solution's config > > To a) here is my local.conf, as you see it's the BB and MAKE thread number > is 4. > > b) yeah, it's a "screen" in an rxvt-unicode in regular X11 environment, > icewm. > Is there a problem with this? I've used screen a lot with Yocto 1.5 and have > not seen anything like this before. screen should work, I'm just trying to figure out how to reproduce this. There is some element of your environment I don't have. FWIW I just tested under screen here and I don't see the problem. Could you share the output of "stty -a" please? Its possible there is some difference in the terminal environment causing this. > c) Debian Unstable, (i.e. Jessie plus X), > $ lsb_release -a > No LSB modules are available. > Distributor ID: Debian > Description: Debian GNU/Linux 8.0 (jessie) > Release: 8.0 > Codename: jessie > $ uname -a > Linux zombie 3.18.0-rc6+ #3 SMP PREEMPT Sat Nov 29 21:03:44 CET 2014 x86_64 > GNU/Linux > $ grep model.name /proc/cpuinfo > model name : AMD Phenom(tm) II X4 955 Processor I don't use this but I think I know someone else who does, I'll ask if they see this. > d) I press Ctrl-C once and I get the situation described yesterday (one > python task is looping with some stat/statfs syscalls inbetween and about 35 > percent CPU consumption, and lots of processes in halted state). > > When I press it again (which usually would invoke the process killer) then I > get the situation that I initially described: > Second Keyboard Interrupt, stopping... > > > Summary: 1 task failed: > > /mnt/exroot/work/yocto/poky/meta/recipes-devtools/opkg/opkg-config-base_1.0. > bb, do_fetch > Summary: There were 4 WARNING messages shown. > Summary: There were 2 ERROR messages shown, returning a non-zero exit code. > Execution was interrupted, returning a non-zero exit code. > NOTE: Sending SIGTERM to remaining 1 tasks > > and now it's really hung and I see a python process consuming 99 percent of > a core and top displays one python task looping on one core: > 6481 xuser 20 0 612232 286504 4484 R 100,4 2,3 104:46.97 > python Its useful to know that things completely hang at that point. Does this always happen or is it intermittent? The signs suggest something is wrong with the job/signal control, I just can't see why only some people would see the issue. There is some difference here we're not seeing. If you could test the setsid() change, that would be useful in helping narrow this down, thanks!
Just to update further, I didn't know anyone with a jessie install so I created a jessie chroot and tried to reproduce there with no success either :(.
Thanks for mentioning os.setpgid, I have read the comment there and it did ring some bells. I am using systemd, maybe this is somehow related? Systemd is obviously running outside of the chroot and might impact the process control (the cgroups magic there). Anyhow, I changed the suggested method call it seems to work now, i.e. it responds to single and double Ctrl-C in the usual way (stopping the queue resp. killing all processes). All this without toaster. And the image build eventually succeeded, after working around this linux-feeds.conf bug but that's a separate issue in meta-alt-desktop-extras, someone needs to fix it. Shall I switch my workstation to sysvinit and make another test run? In the meantime I made a backup (hardlink copy) of the build tree for further experiments. I also tried to build with toaster in background (without the setsid change) and it also works. /mnt/exroot/work/yocto/poky/build-a20 $ stty -a speed 38400 baud; rows 65; columns 141; line = 0; intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = <undef>; eol2 = <undef>; swtch = <undef>; start = ^Q; stop = <undef>; susp = ^Z; rprnt = ^R; werase = ^W; lnext = ^V; flush = ^O; min = 1; time = 0; -parenb -parodd -cmspar cs8 -hupcl -cstopb cread -clocal -crtscts -ignbrk brkint ignpar -parmrk -inpck -istrip -inlcr -igncr icrnl ixon -ixoff -iuclc -ixany imaxbel iutf8 opost -olcuc -ocrnl onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 ff0 isig icanon iexten echo echoe echok -echonl -noflsh -xcase -tostop -echoprt echoctl echoke And thanks again! PS: now after a doing a dozen of build runs bitbake reports some inconsistency and missing files from some toaster data set after finishing... maybe I should purge tmp dir and rebuild the project.
(In reply to comment #10) > Thanks for mentioning os.setpgid, I have read the comment there and it did > ring some bells. I am using systemd, maybe this is somehow related? Systemd > is obviously running outside of the chroot and might impact the process > control (the cgroups magic there). Anyhow, I changed the suggested method > call it seems to work now, i.e. it responds to single and double Ctrl-C in > the usual way (stopping the queue resp. killing all processes). All this > without toaster. Ok, at least confirming that setsid() resolves the issue helps a lot, we know roughly what is happening but not why. Its possible it could be systemd I guess, I really don't know at this point. > And the image build eventually succeeded, after working around this > linux-feeds.conf bug but that's a separate issue in meta-alt-desktop-extras, > someone needs to fix it. Right, that is a separate issue with that layer. > Shall I switch my workstation to sysvinit and make another test run? > > In the meantime I made a backup (hardlink copy) of the build tree for > further experiments. I also tried to build with toaster in background > (without the setsid change) and it also works. > > /mnt/exroot/work/yocto/poky/build-a20 $ stty -a > speed 38400 baud; rows 65; columns 141; line = 0; > intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = <undef>; eol2 = > <undef>; swtch = <undef>; start = ^Q; stop = <undef>; susp = ^Z; > rprnt = ^R; werase = ^W; lnext = ^V; flush = ^O; min = 1; time = 0; > -parenb -parodd -cmspar cs8 -hupcl -cstopb cread -clocal -crtscts > -ignbrk brkint ignpar -parmrk -inpck -istrip -inlcr -igncr icrnl ixon -ixoff > -iuclc -ixany imaxbel iutf8 > opost -olcuc -ocrnl onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 > ff0 > isig icanon iexten echo echoe echok -echonl -noflsh -xcase -tostop -echoprt > echoctl echoke This is interesting, I thought I was onto something when I saw brkint here since none of my terminals have that and the description of it fits. The idea fell apart when setting that on my terminal didn't reproduce the hangs. I did figure out that use of rxvt triggers brkint and some of the other settings above come from using screen. I could't reproduce the hangs though. I still think there is some interprocess signal masking issue going on here, maybe only triggered by the rxvt terminal settings when combined with something else, as yet unknown. > And thanks again! > > PS: now after a doing a dozen of build runs bitbake reports some > inconsistency and missing files from some toaster data set after > finishing... maybe I should purge tmp dir and rebuild the project. Its possible that build is rather confused by now so that may be a good plan. Thanks for persevering with digging into this!
I've merged http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=130958cc24ad306684d92a8d965f3772f30e196a since it appears to be the issue, even if we don't understand the trigger. At this point this is the best I can do. If we do have any more information please do reopen the bug or comment as appropriate.