13992 2020-07-28 07:57:39 +0000 qemumips testimage keeps failing 2021-05-06 15:14:06 +0000 1 1 10 QA/Testing Runtime Testing testimage unspecified x86 mips RESOLVED WORKSFORME AB-INT Medium+ normal 3.4 M1 1 richard.purdie victor.kamensky7 akuster808 alexandre.belloni anuj.mittal bruce.ashfield flowergom jon.mason randy.macleod steve --- --- No (bug/feature does not impact docs) oldest_to_newest 87844 0 richard.purdie 2020-07-28 07:57:39 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/763 (dunfell, qemumips-alt, core-iage-sato) https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/762 (master, qemumips-alt, core-image-sato-sdk) https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/760 (master, qemumips-alt, core-image-sato-sdk) 87850 1 steve 2020-07-29 07:30:39 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/763 (dunfell, qemumips-alt, core-iage-sato, ubuntu2004-ty-2) 87910 2 akuster808 2020-08-11 12:05:39 +0000 trying to reproduce this on a slow centos7 system. One idea was load related so a slower system may replicate this. 87915 3 steve 2020-08-12 11:15:21 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/804 (dunfell, qemumips-alt, core-image-sato-sdk, debian10-ty-3) 87917 4 richard.purdie 2020-08-12 13:55:15 +0000 qemu 5.1 release notes mention slight mips performance improvements which may be something else to investigate. 87922 5 richard.purdie 2020-08-13 05:48:47 +0000 Steve: Was khem's mips qemu cpu option included in that failed build? 87923 6 steve 2020-08-13 06:59:22 +0000 Richard: Yes, this build included the "qemumips: Use 34Kf CPU emulation" patch 87947 7 akuster808 2020-08-14 09:22:21 +0000 I have a low end build system @ home ( 6 cores, 20GiG Ram). If do invoke on bitbake to use all the cpus and then start the testimage, qemu is starved of resources. I am seeing several testimage warning and errors. I will try x86 to see if it has the same behavior. 1) Test requires ldd to be installed WARNING: core-image-sato-sdk-1.0-r0 do_testimage: Couldn't login into serial console as root using blank password WARNING: core-image-sato-sdk-1.0-r0 do_testimage: The output: root <<< run_serial(): command timed out after 60 seconds without output >>> 2) Test requires systemtap to be installed Startup finished in 21.329s (kernel) + 1min 55.569s (userspace) = 2min 16.898s. Target boot time 136.898 exceeds systemd's TimeoutStartSec 90 Failed to reload daemon: Refusing to reload, not enough space available on /run/systemd. Currently, 14.3M are free, but a safety buffer of 16.0M is enforced. 3) Loads of dnf test failures 87948 8 akuster808 2020-08-14 09:22:35 +0000 Testimage local.conf OEBUILDDIR = "/home/akuster" OEBRANCH = "master" SOURCE_MIRROR_URL = "http://downloads.yoctoproject.org/mirror/sources/" SSTATE_MIRRORS = "file://.* http://sstate.yoctoproject.org/dev/PATH;downloadfilename=PATH \n" DL_DIR = "${OEBUILDDIR}/downloads/${OEBRANCH}" SSTATE_DIR = "${OEBUILDDIR}/sstate/${OEBRANCH}" BB_HASHSERVE = "auto" BB_SIGNATURE_HANDLER = "OEEquivHash" SDKMACHINE = "i686" PACKAGE_CLASSES = "package_rpm package_deb package_ipk" IMAGE_CLASSES += "testimage" TEST_QEMUBOOT_TIMEOUT = '1500' INHERIT += 'image-buildinfo' IMAGE_BUILDINFO_VARS_append = ' IMAGE_BASENAME IMAGE_NAME' QEMU_USE_KVM = 'True' DISTRO = "poky-altcfg" 87949 9 akuster808 2020-08-14 09:23:25 +0000 Load: bitbake core-image-full-cmdline core-image-sato core-image-sato-sdk -k SDKMACHINE = "i686" PACKAGE_CLASSES = "package_rpm package_deb package_ipk" IMAGE_CLASSES += "testimage" TEST_QEMUBOOT_TIMEOUT = '1500' INHERIT += 'image-buildinfo' IMAGE_BUILDINFO_VARS_append = ' IMAGE_BASENAME IMAGE_NAME' QEMU_USE_KVM = 'True' DISTRO = "poky-altcfg" MACHINE = "qemumips64" 87950 10 akuster808 2020-08-14 09:24:08 +0000 testimage command: bitbake core-image-full-cmdline core-image-sato core-image-sato-sdk -c testimage 87951 11 akuster808 2020-08-14 09:24:21 +0000 Centos7.7 88055 12 richard.purdie 2020-08-27 23:13:49 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/863 (master, qemumips-alt, core-image-sato) 88058 13 steve 2020-08-28 07:28:40 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/2358 (dunfell, qemumips, core-image-minimal, centos8-ty-2) 88140 14 akuster808 2020-09-10 21:52:52 +0000 (In reply to comment #7) > I have a low end build system @ home ( 6 cores, 20GiG Ram). > > If do invoke on bitbake to use all the cpus and then start the testimage, > > qemu is starved of resources. I am seeing several testimage warning and > errors. > > I will try x86 to see if it has the same behavior. > > 1) Test requires ldd to be installed > WARNING: core-image-sato-sdk-1.0-r0 do_testimage: Couldn't login into serial > console as root using blank password > WARNING: core-image-sato-sdk-1.0-r0 do_testimage: The output: > root > <<< run_serial(): command timed out after 60 seconds without output >>> > > > 2) Test requires systemtap to be installed > Startup finished in 21.329s (kernel) + 1min 55.569s (userspace) = 2min > 16.898s. > Target boot time 136.898 exceeds systemd's TimeoutStartSec 90 > > > Failed to reload daemon: Refusing to reload, not enough space available on > /run/systemd. Currently, 14.3M are free, but a safety buffer of 16.0M is > enforced. I bumped the ram to everyone else's size -m 512 and that seems to have addressed the that error. > > > 3) Loads of dnf test failures 88141 15 akuster808 2020-09-10 21:54:35 +0000 re-running tests with the 'renice' changes 88806 16 anuj.mittal 2020-12-23 06:55:34 +0000 I got this again today while testing gatesgarth: https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/2844/steps/10/logs/step1c 89033 17 alexandre.belloni 2021-01-26 18:35:56 +0000 Previous comment is about test_ping failing (I commented on the other bug). However, this one is about qemu stalling a guest CPU and the guest kernel crashing because of that: https://autobuilder.yoctoproject.org/typhoon/#/builders/74/builds/2942 89178 18 flowergom 2021-02-09 07:47:55 +0000 Happanded again: https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/3032/steps/14/logs/stdio 89220 19 randy.macleod 2021-02-11 15:47:01 +0000 *** Bug 14224 has been marked as a duplicate of this bug. *** 89331 20 victor.kamensky7 2021-02-20 04:10:39 +0000 Here is partial RCA, unfortunately it is still not clear what excactly the problem. But what is clear that it is related to kernel page migration/compaction function that does not work very well with MIPS kernel HIGHMEM that is needed for 512Mb. As per last note I've tried MIPS kernel with disabled compaction, and hang problem does not appear anymore. Removing CONFIG_COMPACTION from 32 MIPS kernel config may seem as reasonable workaround for purposes of Yocto poky testing. Kernel compaction/migration code deals with kernel memory fragmentation issues o Reproduced problem on local setup. Under qemu with kernel debug observed the following tracebacks: (gdb) bt #0 0x80195038 in queued_spin_lock_slowpath (lock=0x8cec163c, val=<optimized out>) at kernel/locking/qspinlock.c:382 #1 0x8030ad80 in spin_lock (lock=<optimized out>) at ./include/linux/spinlock.h:353 #2 follow_page_pte (pgmap=<optimized out>, flags=<optimized out>, pmd=<optimized out>, address=<optimized out>, vma=<optimized out>) at mm/gup.c:420 #3 follow_pmd_mask (vma=0x1, address=2138641893, pudp=0x8cfc57f4, flags=41479, ctx=<optimized out>) at mm/gup.c:609 #4 0x8030b278 in follow_pud_mask (ctx=<optimized out>, flags=<optimized out>, p4dp=<optimized out>, address=<optimized out>, vma=<optimized out>) at mm/gup.c:704 #5 follow_p4d_mask (ctx=<optimized out>, flags=<optimized out>, pgdp=<optimized out>, address=<optimized out>, vma=<optimized out>) at mm/gup.c:730 #6 follow_page_mask (ctx=<optimized out>, flags=<optimized out>, address=<optimized out>, vma=<optimized out>) at mm/gup.c:789 #7 __get_user_pages (tsk=0x0, mm=0x8cec1600, start=2138641893, nr_pages=1, gup_flags=41478, pages=0x8e4fbe08, vmas=0x8e4fbe04, locked=0x0) at mm/gup.c:1111 #8 0x8030b6e8 in __get_user_pages_locked (flags=<optimized out>, locked=<optimized out>, vmas=<optimized out>, pages=0x8e4fbe08, nr_pages=<optimized out>, start=<optimized out>, mm=<optimized out>, tsk=<optimized out>) at mm/gup.c:1306 #9 __get_user_pages_remote (tsk=0x0, mm=0x8cec1600, start=2138641893, nr_pages=<optimized out>, gup_flags=<optimized out>, pages=0x8e4fbe08, vmas=<optimized out>, locked=0x0) at mm/gup.c:1857 #10 0x80314808 in __access_remote_vm (tsk=0x0, mm=0x8cec1600, addr=2138641893, buf=0x8e4fbe7b, len=1, gup_flags=32768) at mm/memory.c:4694 #11 0x80314a40 in access_remote_vm (mm=<optimized out>, addr=<optimized out>, buf=<optimized out>, len=<optimized out>, gup_flags=<optimized out>) at mm/memory.c:4756 #12 0x80404164 in get_mm_cmdline (ppos=<optimized out>, count=<optimized out>, buf=0x5566d190 "/bin/sh", mm=<optimized out>) at fs/proc/base.c:301 #13 get_task_cmdline (pos=<optimized out>, count=<optimized out>, buf=<optimized out>, tsk=<optimized out>) at fs/proc/base.c:352 #14 proc_pid_cmdline_read (file=<optimized out>, buf=0x5566d190 "/bin/sh", count=<optimized out>, pos=0x8e4fbf00) at fs/proc/base.c:368 #15 0x8035bb8c in vfs_read (file=0x8e5af0c0, buf=0x5566d190 "/bin/sh", count=<optimized out>, pos=0x8e4fbf00) at fs/read_write.c:479 #16 0x8035d474 in ksys_read (fd=<optimized out>, buf=0x5566d190 "/bin/sh", count=20) at fs/read_write.c:633 #17 0x80118304 in handle_sys () at arch/mips/kernel/scall32-o32.S:99 Backtrace stopped: frame did not save the PC or another variant (gdb) bt #0 0x80196eb8 in queued_spin_lock_slowpath (lock=0x8e31b8fc, val=<optimized out>) at kernel/locking/qspinlock.c:382 #1 0x80198848 in queued_spin_lock (lock=<optimized out>) at ./include/asm-generic/qspinlock.h:81 #2 do_raw_spin_lock (lock=0x8e31b8fc) at kernel/locking/spinlock_debug.c:113 #3 0x80314b54 in spin_lock (lock=<optimized out>) at ./include/linux/spinlock.h:353 #4 zap_pte_range (tlb=0x8c80fba8, vma=<optimized out>, pmd=<optimized out>, addr=1432166400, end=1433374720, details=0x0) at mm/memory.c:1048 #5 0x80315b10 in zap_pmd_range (details=<optimized out>, end=<optimized out>, addr=1432166400, pud=<optimized out>, vma=<optimized out>, tlb=<optimized out>) at mm/memory.c:1194 #6 zap_pud_range (details=<optimized out>, end=<optimized out>, addr=<optimized out>, p4d=<optimized out>, vma=<optimized out>, tlb=<optimized out>) at mm/memory.c:1223 #7 zap_p4d_range (details=<optimized out>, end=<optimized out>, addr=<optimized out>, pgd=<optimized out>, vma=<optimized out>, tlb=<optimized out>) at mm/memory.c:1244 #8 unmap_page_range (tlb=0x8c80fba8, vma=0x8dca1f00, addr=1432166400, end=1433374720, details=0x0) at mm/memory.c:1265 #9 0x80315e88 in unmap_single_vma (details=<optimized out>, end_addr=<optimized out>, start_addr=<optimized out>, vma=<optimized out>, tlb=<optimized out>) at mm/memory.c:1310 #10 unmap_vmas (tlb=0x8c80fba8, vma=0x8dca1f00, start_addr=0, end_addr=4294967295) at mm/memory.c:1342 #11 0x8031ed28 in exit_mmap (mm=0x8e31b8c0) at mm/mmap.c:3179 #12 0x801322a4 in __mmput (mm=<optimized out>) at kernel/fork.c:1093 #13 mmput (mm=0x8e31b8c0) at kernel/fork.c:1114 #14 0x8013b134 in exit_mm () at kernel/exit.c:482 #15 do_exit (code=<optimized out>) at kernel/exit.c:792 #16 0x8010f998 in die (str=0x80ef0cf0 "Kernel bug detected", regs=0x8c80fd30) at arch/mips/kernel/traps.c:415 #17 0x80110150 in die_if_kernel (regs=<optimized out>, str=<optimized out>) at ./arch/mips/include/asm/ptrace.h:167 #18 do_trap_or_bp (regs=0x8c80fd30, code=12, si_code=<optimized out>, str=0x80ef0d40 "Trap") at arch/mips/kernel/traps.c:990 #19 0x80110580 in do_tr (regs=0x8c80fd30) at arch/mips/kernel/traps.c:1141 #20 0x801092b8 in handle_tr () at arch/mips/kernel/genex.S:553 Backtrace stopped: frame did not save the PC In all cases page lock seems to be corrupted. Example: (gdb) p *lock $3 = {{val = {counter = 257}, {tail = 0, locked_pending = 257}, {reserved = "\000", pending = 1 '\001', locked = 1 '\001'}}} o It turns out and as last traceback suggests, above crashes are actually secondary problem. They do really hit corrupted lock, but first issue is really triggered by BUG_ON in migration_entry_to_page (gdb) bt #0 0x8034d05c in __BUG_ON (condition=<optimized out>) at ./arch/mips/include/asm/bug.h:30 #1 migration_entry_to_page (entry=...) at ./include/linux/swapops.h:197 #2 __migration_entry_wait (mm=<optimized out>, ptep=<optimized out>, ptl=<optimized out>) at mm/migrate.c:328 #3 0x80317b74 in do_swap_page (vmf=0x8dcafe78) at mm/memory.c:3115 #4 0x80318af8 in handle_pte_fault (vmf=<optimized out>) at mm/memory.c:4239 #5 __handle_mm_fault (flags=<optimized out>, address=<optimized out>, vma=<optimized out>) at mm/memory.c:4370 #6 handle_mm_fault (vma=0x8e0ae060, address=<optimized out>, flags=596) at mm/memory.c:4407 #7 0x80cc5784 in __do_page_fault (address=<optimized out>, write=<optimized out>, regs=<optimized out>) at arch/mips/mm/fault.c:155 #8 do_page_fault (regs=0x8dcaff28, write=0, address=1433989548) at arch/mips/mm/fault.c:338 #9 0x801227c4 in tlb_do_page_fault_0 () at arch/mips/mm/tlbex-fault.S:27 Backtrace stopped: frame did not save the PC (gdb) f 1 #1 migration_entry_to_page (entry=...) at ./include/linux/swapops.h:197 197 BUG_ON(!PageLocked(compound_head(p))); (gdb) list 192 struct page *p = pfn_to_page(swp_offset(entry)); 193 /* 194 * Any use of migration entries may only occur while the 195 * corresponding page is locked 196 */ 197 BUG_ON(!PageLocked(compound_head(p))); 198 return p; 199 } o Further debugging of mips highmem and kernel migration/compaction did not produce anything useful. Code is quite complicated and logic is not clear. o Run experiment, where otherwise all same setup, I've disabled kernel migration/compaction code, and hand issue was not observed anymore. Here is diff kernel config diff. Essential part is to disable CONFIG_COMPACTION, i.e 'CONFIG_COMPACTION is not set' it would automatically clear CONFIG_BALLOON_COMPACTION=y and CONFIG_MIGRATION=y because of dependency. 606,607c606 < CONFIG_BALLOON_COMPACTION=y < CONFIG_COMPACTION=y --- > # CONFIG_COMPACTION is not set 609d607 < CONFIG_MIGRATION=y o Removing CONFIG_COMPACTION from 32 MIPS kernel config may seem as reasonable workaround for purposes of Yocto poky testing. Kernel compaction/migration code deals with kernel memory fragmentation issues and given that test is relatively short, system would be OK even without memory compaction. o As other experiment under poky test load with kernel breakpoint in compaction code I observed that compation did not trigger at all through first half part of the test. And actually as soon it got triggered mention BUG_ON was hit on page that was involved in migration. 89332 21 richard.purdie 2021-02-20 11:34:28 +0000 Thanks Victor, its great analysis, that might be a good enough fix for our needs. Bruce, should we enable this on 32 bit mips kernels? 89345 22 bruce.ashfield 2021-02-23 01:15:41 +0000 (In reply to comment #21) > Thanks Victor, its great analysis, that might be a good enough fix for our > needs. Bruce, should we enable this on 32 bit mips kernels? I'm ok with changing those values on the 32bit mips kernels. I can prepare change to the meta-data for testing on the AB. 89346 23 bruce.ashfield 2021-02-23 02:06:25 +0000 http://git.yoctoproject.org/cgit.cgi/poky-contrib/commit/?h=zedd/kernel&id=cfc7e124bd3e0ccdc1ba77e32991a839f427f92b Is available for testing. I'll also include it in my next consolidated pull request. 89449 24 alexandre.belloni 2021-03-01 00:29:00 +0000 This is an occurrence from last week: https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/3106/steps/13/logs/stdio 90290 25 randy.macleod 2021-05-06 15:14:06 +0000 Not seen since the page table code changes and moving the rootfs to tmpfs.