| Summary: | master dnf failures on qemumips | ||
|---|---|---|---|
| Product: | [Build System, Metadata & Runtime] OE-Core | Reporter: | Richard Purdie <richard.purdie> |
| Component: | core | Assignee: | Unassigned <unassigned> |
| Status: | RESOLVED FIXED | QA Contact: | |
| Severity: | normal | ||
| Priority: | Medium+ | CC: | hongxu.jia, liezhi.yang, mathieu.dubois-briand, meta.mr.watcher, meta.watcher, paulg, pavel, randy.macleod, ross.burton, tgamblin, yoann.congal |
| Version: | 3.0 | ||
| Target Milestone: | 5.2 M4 | ||
| 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
Richard Purdie
2019-12-04 13:06:51 UTC
Occurs relatively rarely (every month or so) but it is important that the autobuilder tests be fixed. Not seen on autobuilder but it has been encountering other errors so let's check next week. Unassigned assuming that this is only mips, I don't think WR has an interest in this bug. Bulk move of 64 bugs to 4.3 M3 after a quick review. If a bug is actually fixed, please add a commit link and resolve it. -- Randy for YP bug team. Moved to M4. Bulk move to 5.0 M1. -- Randy Bulk move of 52 5.0-M1 bugs to M2. Bulk move of bugs owned by "unassigned" from 5.0-M2 to 5.0-M3. Bulk move of bugs from 5.0-M3 to 5.99. The bugs in this list are all unassigned and are ones that I consider to be nice to do some time but not essential track from milestone to milestone in 5.0 or 5.1. We agreed on this bug handling approach in the YP bug review on Feb 22, 2024. If you disagree, please move back to a 5.[012...]-M* milestone. qemumips64 debian11-vk-2 master completed at 2024-12-15T11:36:09Z https://valkyrie.yoctoproject.org/#/builders/32/builds/635/steps/14/logs/stdio qemumips64 debian12-vk-6 mathieu/master-next completed at 2024-12-18T10:18:05Z https://valkyrie.yoctoproject.org/#/builders/32/builds/662/steps/13/logs/stdio Also on ARM: meta-arm ubuntu2004-vk-2 mathieu/master-next completed at 2024-12-23T10:01:34Z https://valkyrie.yoctoproject.org/#/builders/75/builds/635/steps/17/logs/stdio qemumips64 ubuntu2004-vk-3 master completed at 2024-12-26T01:23:12Z https://valkyrie.yoctoproject.org/#/builders/32/builds/690/steps/14/logs/stdio And now this one is on qemuarmv5, so maybe the bug seen during the last few days is not exactly the same as previously. qemuarmv5 alma9-vk-1 master completed at 2024-12-28T04:21:37Z https://valkyrie.yoctoproject.org/#/builders/80/builds/641/steps/14/logs/stdio qemuppc alma9-vk-1 master completed at 2024-12-30T04:02:21Z https://valkyrie.yoctoproject.org/#/builders/31/builds/707/steps/14/logs/stdio qemumips64 fedora39-vk-1 master completed at 2025-01-01T01:24:43Z https://valkyrie.yoctoproject.org/#/builders/32/builds/710/steps/14/logs/stdio qemumips64 alma9-vk-2 master-next completed at 2025-01-01T12:14:40Z https://valkyrie.yoctoproject.org/#/builders/32/builds/711/steps/14/logs/stdio qemumips64 opensuse155-vk-1 mathieu/master-next completed at 2025-01-02T09:44:32Z https://valkyrie.yoctoproject.org/#/builders/32/builds/714/steps/14/logs/stdio qemumips64 debian12-vk-8 mathieu/master-next completed at 2025-01-02T17:34:04Z https://valkyrie.yoctoproject.org/#/builders/32/builds/719/steps/13/logs/stdio qemumips64 alma9-vk-1 abelloni/master-next completed at 2025-01-05T19:57:32Z https://valkyrie.yoctoproject.org/#/builders/32/builds/736/steps/14/logs/stdio qemumips64 rocky9-vk-1 master completed at 2025-01-06T01:32:04Z https://valkyrie.yoctoproject.org/#/builders/32/builds/737/steps/14/logs/stdio qemumips64 debian11-vk-1 abelloni/master-next completed at 2025-01-06T11:25:01Z https://valkyrie.yoctoproject.org/#/builders/32/builds/738/steps/14/logs/stdio qemumips64 alma9-vk-1 master-next completed at 2025-01-06T15:08:13Z https://valkyrie.yoctoproject.org/#/builders/32/builds/739/steps/14/logs/stdio qemumips64 stream9-vk-1 master completed at 2025-01-07T01:33:36Z https://valkyrie.yoctoproject.org/#/builders/32/builds/744/steps/14/logs/stdio qemumips64 ubuntu2204-vk-4 master-next completed at 2025-01-07T22:57:15Z https://valkyrie.yoctoproject.org/#/builders/32/builds/754/steps/14/logs/stdio meta-arm alma8-vk-2 abelloni/master-next completed at 2025-01-12T19:45:43Z https://valkyrie.yoctoproject.org/#/builders/75/builds/731/steps/18/logs/stdio meta-arm debian11-vk-1 master-next completed at 2025-01-17T11:41:58Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/75/builds/762/steps/17/logs/stdio qemumips64 rocky9-vk-2 master-next completed at 2025-01-16T12:11:38Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/808/steps/14/logs/stdio it's strange, I tried it many times locally, but can't reproduce the error qemumips64 ubuntu2404-vk-2 mathieu/master-next completed at 2025-01-22T09:55:12Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/848/steps/13/logs/stdio qemumips64 ubuntu2004-vk-1 master-next completed at 2025-01-22T12:21:01Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/850/steps/14/logs/stdio I did a deep dive into one of these. https://autobuilder.yocto.io/pub/failed-builds-data/qemumips64-dnf/log.do_testimage.293138 - is the testimage log of the test_dnf_installroot test failure. Inside https://autobuilder.yocto.io/pub/failed-builds-data/qemumips64-dnf/tests_artifacts.tar.gz is a dnf.rpm.log There is weirdness is this set of lines: 2025-01-22T19:42:32+0000 INFO --- logging initialized --- 2025-01-22T19:43:22+0000 SUBDEBUG Reinstall: dnf-test-main-4.22.0-r0.mips64r2 2025-01-22T19:43:22+0000 SUBDEBUG Reinstalled: dnf-test-main-4.22.0-r0.mips64r2 2025-01-22T19:43:44+0000 INFO --- logging initialized --- 2025-01-22T19:46:00+0000 INFO D: exiting chroot /home/root/chroot/test/ which implies the reinstall test is running when the installroot test is still active too. Since the installroot is separate, that is possible. The ssh connection for the test seems to fail, exit code 255. I don't believe the command fails, I believe the connection fails. In the "messages" log in the above archive, there is also this: Jan 22 19:40:34 qemumips64 authpriv.info dropbear[693]: Child connection from 192.168.7.1:41410 Jan 22 19:40:34 qemumips64 authpriv.notice dropbear[693]: Auth succeeded with blank password for 'root' from 192.168.7.1:41410 Jan 22 19:42:05 qemumips64 authpriv.info dropbear[2213]: Child connection from 192.168.7.1:44380 Jan 22 19:42:07 qemumips64 authpriv.notice dropbear[2213]: Auth succeeded with blank password for 'root' from 192.168.7.1:44380 Jan 22 19:43:22 qemumips64 authpriv.info dropbear[693]: Exit (root) from <192.168.7.1:41410>: Error writing: Broken pipe Jan 22 19:43:27 qemumips64 authpriv.info dropbear[2213]: Exit (root) from <192.168.7.1:44380>: Disconnect received Jan 22 19:43:27 qemumips64 authpriv.info dropbear[3541]: Child connection from 192.168.7.1:40790 i.e. it failed to write to the remote. I was wondering if the ssh server had OOM'd however this looks like like the networking to 192.168.7.1 glitched. qemumips64 rocky9-vk-1 master-next completed at 2025-01-22T19:52:41Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/857/steps/14/logs/stdio qemumips64 debian12-vk-9 mathieu/master-next completed at 2025-01-27T08:38:55Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/882/steps/13/logs/stdio Potentially maybe fixed with oe-core 9d91a5674c515a43ae76d8615f72e5e2dc16c961? Bulk move. qemumips64 debian12-vk-4 mathieu/master-next completed at 2025-02-06T12:08:28Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/937/steps/13/logs/stdio qemumips64 opensuse155-vk-1 master-next completed at 2025-02-07T12:08:35Z Lot of dnf failures this week because of bad patches. I believe this one is because of the AB-INT, but I might be wrong. https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/948/steps/15/logs/stdio qemumips64 ubuntu2004-vk-2 master completed at 2025-02-12T02:11:54Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/980/steps/14/logs/stdio Robert, this is a frequent issue for the YP AB. Can we get someone working on this ASAP? qemumips64 opensuse156-vk-1 master-next completed at 2025-03-03T13:44:13Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1091/steps/15/logs/stdio qemumips64 debian12-vk-1 mathieu/master-next completed at 2025-03-07T07:23:32Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1119/steps/13/logs/stdio qemumips64 ubuntu2004-vk-1 master completed at 2025-03-07T12:07:33Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1122/steps/14/logs/stdio qemumips64 alma8-vk-2 master-next completed at 2025-03-12T17:36:12Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1159/steps/15/logs/stdio This is a difficult bug to reproduce, it's likely load related. Can we add some logs to help diagnose the issue. Something along the lines of the 'run_cmds' function in : https://git.yoctoproject.org/poky/tree/scripts/oe-time-dd-test.sh#n31 This is rather verbose so we have an offline script to generate a summary: https://git.yoctoproject.org/yocto-autobuilder-helper/tree/scripts/summarize_top_output.py It's not clear to me what the conditions merit such data collection. I'm off work tomorrow (Friday) so I'll try to make time to work on that next week if no one has gotten there first. Locally I couldn't reproduce this. I tried to reproduce using a failed autobuilder build directory and initially it didn't. When there were builds running in parallel (including an oe-selftest), it did reproduce. Locally, I did manage test failures with ssh hanging if I ran "cpulimit -l 50" on the qemu pid as it started from a "bitbake core-image-sato -c testimage" but not the same test failure. The kernel looks showed rcu-stalls and weird timestamps. I noticed there is a suspicious looking CONFIG_QEMUMIPS64 kernel config we're nt setting which changes clock/interrupt config. sched_clock: 64 bits at 100 Hz, resolution 10000000ns, wraps every 36028797015000000ns becomes: clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 11945313065 ns sched_clock: 32 bits at 160MHz, resolution 6ns, wraps every 13421700092ns clocksource: Switched to clocksource MIPS with that config set. We should probably try setting that and seeing if these issues change in frequency. I do 100% agree. Using a 100Hz jiffy clock is so y2k that it is not funny. It made sense back in the day as a valid trade-off in order to optimize toward bulk processing with a larger time slice on these old processors, before scribbling the tiny cache with a timer interrupt. But time moves on, and even 15(?) years ago the default was 1kHz because processors got faster and people started to care about resolution. Using a 6.x kernel on an ancient CPU model with a 100Hz clock definitely puts us in a spot where very few (if nobody else?) is testing. CONFIG_QEMUMIPS64 comes from one of our kernel patches. This disables a couple of different clock sources. Looking at upstream, there is https://web.git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/arch/mips?id=078b831638e1aa06dd7ffa9f244c8ac6b2995561 which also changes one of the two clock sources the above changes. Testing locally, I don't see the rcu-stalls with this backported so I think the best thing we can do is backport the above revert from mainline. qemumips64 alma9-vk-2 master completed at 2025-03-14T01:24:20Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1170/steps/14/logs/stdio qemumips64 ubuntu2204-vk-2 master-next completed at 2025-03-17T22:52:25Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1186/steps/14/logs/stdio qemumips64 alma9-vk-2 master-next completed at 2025-03-19T15:45:45Z https://autobuilder.yoctoproject.org/valkyrie/#/builders/32/builds/1202/steps/14/logs/stdio The fix was included in the kernel upgrade: https://git.yoctoproject.org/poky/commit/?id=808fb969bc8c3dafda87ddfd813fae832eb6917c so we'll work on the basis that fixes this. We should start a new bug for any issuea after this is merged. |