| Summary: | Intermittent qemu connection failures during oe-selftest on autobuilder | ||
|---|---|---|---|
| Product: | [Build System, Metadata & Runtime] OE-Core | Reporter: | Steve Sakoman <steve> |
| Component: | core | Assignee: | Sakib Sajal <sakib.sajal> |
| Status: | RESOLVED OBSOLETE | QA Contact: | |
| Severity: | normal | ||
| Priority: | Medium+ | CC: | matthew.zeng, matthewzmd, meta.mr.watcher, meta.watcher, randy.macleod, richard.purdie |
| Version: | 3.1 | ||
| Target Milestone: | 3.4 M3 | ||
| Hardware: | x86 | ||
| OS: | Multiple | ||
| Whiteboard: | AB-INT | ||
| OS type for building Yocto: | --- | Type of Regression: | --- |
| Verified: | Documentation change: | No (bug/feature does not impact docs) | |
|
Description
Steve Sakoman
2020-06-18 08:57:02 UTC
Seems to be dunfell specific according to Richard. Could be a stuck tap device. Had a spate of these in https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1120 Sakib, please get started with this one this week and once you have a handle on it, we can brainstorm how to proceed. The logs are odd as it shouldn't happen, qemu *is* running, oeqa code just isn't seeing it. I added http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=71772fbaea840da03835782b8602613895cf02ce for extra debug and http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=0c1c6c971de40ec3c9094a3963e5b6cc063b0e64 as a potential fix (although I couldn't spot any chdir). If/when the issue does reoccur we may at least be able to get more information. Still seeing the failures, master-next, included the new debug output: https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1159 Good and bad, we now have more data, the problem definitely isn't fixed. That logs shows full pathnames to the pid file being specified, The pid file is never created and the ps output shows the qemu process is running. It seems odd that it wouldn't write the file after 2 minutes. I was thinking these processes had priority as we set: BB_TASK_NICE_LEVEL = '5' BB_TASK_NICE_LEVEL_task-testimage = '0' BB_TASK_IONICE_LEVEL = '2.7' BB_TASK_IONICE_LEVEL_task-testimage = '2.1' however qemu run outside of testimage tasks doesn't get this benefit. Perhaps we should look at addressing that for runqemu launched processes? Unfortunately due to the way nice levels work, you need to drop nice level in the places you don't want it rather than being able to raise it in critical sections and I think you can only lower, not raise so the core scheduling process has to have the higher level. To get an idea of the system load, I tried to write out what it was running in parallel when this failed: a) compiling cairo b) core-image-sato-dev do_image_wic c) core2-32 gobject-introspection compile (running g-ir-scanner) d) qemuarm64 running under qemu for core-image-sato-sdk e) qemuarm-alt running under qemu for core-image-lsb-sdk f) meta-intel target gcc do_compile g) core2-32 gettext do_configure h) meta-intel tcl do_install_ptest i) meta-intel grub-efi do_compile j) meta-intel boost do_compile k) perl boost do_install_ptest l) selftest devtool modify virtual/kernel m) selftest wic image creation n) qemux86-64 core-image-sato-sdk image build (plus probably other selftest bits). That is a fairly heavy workload :/. https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1177 is a failure with much lower system load. It has prioirity/nice info showing that most of the builds are "nice 5" but qemu is "nice 0" meaning it should have priority. Had a nice theory about the pidfile name being the issue and added a patch in master-next to avoid that potential issue. Failures still occur so its not that: https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1178 Further notes: On my local build server sudo sh -c "echo 3 > /proc/sys/vm/drop_caches" then run qemu, pid takes 1.6s to appear qemu-system-x86_64 <options> -enable-kvm -snapshot -pidfile /media/build1/poky/rptest & while true; do date +%S:%N; cat /media/build1/poky/rptest; if [ "$?" == "0" ]; then break; fi; done; dd if=/dev/zero of=loadfile bs=1M count=1024; while true; do cp loadfile loadfile1; done on the other terminal makes it take 4.4s Comparing logs with our dropcaches on the autobuilder: failure log: DEBUG: waiting at most 120 seconds for qemu pid (07/21/20 22:16:14) ERROR: Qemu pid didn't appear in 120 seconds (07/21/20 22:18:19) dmesg: [Tue Jul 21 16:00:57 2020] dropcache (24724): drop_caches: 3 [Wed Jul 22 00:02:18 2020] dropcache (12281): drop_caches: 3 so no correlation. Theory #4, the nice level of the janitor cleanup process needs to be set higher. We're now testing with http://git.yoctoproject.org/cgit.cgi/yocto-autobuilder-helper/commit/?id=29a1c23b292b4e762f01c4c707aee6ea39e0589f applied since both recent traces had janitor rm activity shown in the ps traces. Would be good to go through the previous failures and see if this is a pattern. Hate to say it but I think https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1188 means this is still an issue (was a dunfell build, rm from janitor was nice/ionice but the devtool deletion from selftest was not so maybe that was the issue here?) Another occurrence on a dunfell build: https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/1214 There are more specific bugs to cover this issue. |