Comment # 14
on bug 1188896
from Sarah Kriesch
We had additional issues, but I had a problem receiving a dump for analyzing.
Christian Borntr���ger gave me the hint with "dump-guest-memory" istead of
vmstate.
Here is the dmesg output inside of the crash tool:
WARNING: kernel relocated [3150MB]: patching 91218 gdb minimal_symbol values
WARNING: kernel version inconsistency between vmlinux and dumpfile
WARNING: forcing cpu count to: 3
please wait... (gathering task table data)
crash: invalid kernel virtual address: 2aa3abc7a50 type: "fill_task_struct"
KERNEL: ./boot/vmlinux-5.13.8-2-default.xz
DEBUGINFO: /usr/lib/debug/boot/vmlinux-5.13.8-2-default.debug
DUMPFILE: s390zl21.memory.dump
CPUS: 3 [OFFLINE: 1]
DATE: Thu Aug 19 05:30:29 EDT 2021
UPTIME: 2 days, 16:23:24
LOAD AVERAGE: 9.00, 9.00, 9.00
TASKS: 73
NODENAME: s390zl21
RELEASE: 5.13.8-1-default
VERSION: #1 SMP Thu Aug 5 08:56:22 UTC 2021 (967c6a8)
MACHINE: s390x (unknown Mhz)
MEMORY: 4 GB
PANIC: ""
PID: 0
COMMAND: "swapper/0"
TASK: c60c3a00 (1 of 2) [THREAD_INFO: c60c3a00]
CPU: 0
STATE: TASK_RUNNING
INFO: no panic task found
crash> dmesg
[223279.797135] [<00000000c50061ec>] rcu_gp_kthread+0xabc/0x1280
[223279.797139] [<00000000c4fa1ecc>] kthread+0x14c/0x160
[223279.797143] [<00000000c4f2b56c>] __ret_from_fork+0x3c/0x60
[223279.797146] [<00000000c58bbc3a>] ret_from_fork+0xa/0x30
[223279.797147] rcu: Stack dump where RCU GP kthread last ran:
[223279.797221] Task dump for CPU 1:
[223279.797222] task:cc1plus state:R running task stack: 0 pid:
2431 ppid: 2430 flags:0x00000004
[223279.797226] Call Trace:
[223279.797226] [<00000000c58a6774>] show_stack+0x8c/0xd8
[223279.797229] [<00000000c4fad58c>] sched_show_task+0x14c/0x170
[223279.797231] [<00000000c58a84a6>]
rcu_check_gp_kthread_starvation+0x15e/0x180
[223279.797233] [<00000000c500889c>] rcu_sched_clock_irq+0x7fc/0x990
[223279.797235] [<00000000c5019caa>] update_process_times+0xba/0xf0
[223279.797239] [<00000000c502c67a>] tick_sched_handle+0x4a/0x70
[223279.797241] [<00000000c502ca76>] tick_sched_timer+0x76/0xe0
[223279.797242] [<00000000c501a856>] __hrtimer_run_queues+0x136/0x290
[223279.797244] [<00000000c501b8a0>] hrtimer_interrupt+0x150/0x380
[223279.797246] [<00000000c4f34d56>] do_IRQ+0x56/0x70
[223279.797248] [<00000000c4f35134>] do_irq_async+0x54/0xb0
[223279.797251] [<00000000c58adade>] do_ext_irq+0x9e/0x150
[223279.797252] [<00000000c58bbe80>] ext_int_handler+0xc0/0xf0
[223279.797253] [<00000000c555d024>] xas_load+0x44/0xc0
[223279.797259] [<00000000c5145452>] pagecache_get_page+0x82/0x500
[223279.797264] [<00000000c5145f14>] filemap_fault+0x84/0x880
[223279.797265] [<00000000c532bd4c>] ext4_filemap_fault+0x4c/0x70
[223279.797269] [<00000000c518bc0c>] __do_fault+0x4c/0xf0
[223279.797273] [<00000000c519114c>] __handle_mm_fault+0xc1c/0x1300
[223279.797274] [<00000000c5191904>] handle_mm_fault+0xd4/0x220
[223279.797276] [<00000000c4f506ac>] do_exception+0x18c/0x420
[223279.797278] [<00000000c4f50cda>] do_dat_exception+0x2a/0x60
[223279.797280] [<00000000c58ad6a2>] __do_pgm_check+0x132/0x250
[223279.797281] [<00000000c58bbd78>] pgm_check_handler+0x118/0x160
[223459.838813] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[223459.840823] (detected by 0, t=22300491 jiffies, g=11737, q=1164)
[223459.840828] rcu: All QSes seen, last rcu_sched kthread activity 22300488
(4317283024-4294982536), jiffies_till_next_fqs=1, root ->qsmask 0x0
[223459.840897] rcu: rcu_sched kthread starved for 22300488 jiffies! g11737
f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[223459.840950] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM
is now expected behavior.
[223459.840996] rcu: RCU grace-period kthread stack dump:
[223459.841024] task:rcu_sched state:R running task stack: 0 pid:
13 ppid: 2 flags:0x00000000
[223459.841029] Call Trace:
[223459.841031] [<00000000c58b5336>] __schedule+0x366/0x9b0
[223459.841040] [<00000000c58b59e0>] schedule+0x60/0x100
[223459.841042] [<00000000c58bab9c>] schedule_timeout+0x8c/0x170
[223459.841045] [<00000000c50061ec>] rcu_gp_kthread+0xabc/0x1280
[223459.841048] [<00000000c4fa1ecc>] kthread+0x14c/0x160
[223459.841052] [<00000000c4f2b56c>] __ret_from_fork+0x3c/0x60
[223459.841055] [<00000000c58bbc3a>] ret_from_fork+0xa/0x30
[223459.841057] rcu: Stack dump where RCU GP kthread last ran:
[223459.841084] Task dump for CPU 1:
[223459.841085] task:cc1plus state:R running task stack: 0 pid:
2431 ppid: 2430 flags:0x00000004
[223459.841088] Call Trace:
[223459.841089] [<0000000000000000>] 0x0
[223639.888971] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[223639.948065] (detected by 1, t=22318496 jiffies, g=11737, q=1164)
[223639.948072] rcu: All QSes seen, last rcu_sched kthread activity 22318493
(4317301029-4294982536), jiffies_till_next_fqs=1, root ->qsmask 0x0
[223639.948141] rcu: rcu_sched kthread starved for 22318493 jiffies! g11737
f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[223639.948194] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM
is now expected behavior.
[223639.948239] rcu: RCU grace-period kthread stack dump:
[223639.948265] task:rcu_sched state:R running task stack: 0 pid:
13 ppid: 2 flags:0x00000000
[223639.948270] Call Trace:
[223639.948272] [<00000000c58b5336>] __schedule+0x366/0x9b0
[223639.948281] [<00000000c58b59e0>] schedule+0x60/0x100
[223639.948283] [<00000000c58bab9c>] schedule_timeout+0x8c/0x170
[223639.948286] [<00000000c50061ec>] rcu_gp_kthread+0xabc/0x1280
[223639.948289] [<00000000c4fa1ecc>] kthread+0x14c/0x160
[223639.948293] [<00000000c4f2b56c>] __ret_from_fork+0x3c/0x60
[223639.948296] [<00000000c58bbc3a>] ret_from_fork+0xa/0x30
[223639.948298] rcu: Stack dump where RCU GP kthread last ran:
[223639.948325] Task dump for CPU 1:
[223639.948326] task:cc1plus state:R running task stack: 0 pid:
2431 ppid: 2430 flags:0x00000004
[223639.948329] Call Trace:
[223639.948329] [<00000000c58a6774>] show_stack+0x8c/0xd8
[223639.948332] [<00000000c4fad58c>] sched_show_task+0x14c/0x170
[223639.948334] [<00000000c58a84a6>]
rcu_check_gp_kthread_starvation+0x15e/0x180
[223639.948336] [<00000000c500889c>] rcu_sched_clock_irq+0x7fc/0x990
[223639.948338] [<00000000c5019caa>] update_process_times+0xba/0xf0
[223639.948342] [<00000000c502c67a>] tick_sched_handle+0x4a/0x70
[223639.948344] [<00000000c502ca76>] tick_sched_timer+0x76/0xe0
[223639.948346] [<00000000c501a856>] __hrtimer_run_queues+0x136/0x290
[223639.948347] [<00000000c501b8a0>] hrtimer_interrupt+0x150/0x380
[223639.948349] [<00000000c4f34d56>] do_IRQ+0x56/0x70
[223639.948352] [<00000000c4f35134>] do_irq_async+0x54/0xb0
[223639.948355] [<00000000c58adade>] do_ext_irq+0x9e/0x150
[223639.948356] [<00000000c58bbe80>] ext_int_handler+0xc0/0xf0
[223639.948357] [<00000000c555d070>] xas_load+0x90/0xc0
[223639.948362] ([<00000000c5145452>] pagecache_get_page+0x82/0x500)
[223639.948366] [<00000000c5145f14>] filemap_fault+0x84/0x880
[223639.948368] [<00000000c532bd4c>] ext4_filemap_fault+0x4c/0x70
[223639.948371] [<00000000c518bc0c>] __do_fault+0x4c/0xf0
[223639.948375] [<00000000c519114c>] __handle_mm_fault+0xc1c/0x1300
[223639.948377] [<00000000c5191904>] handle_mm_fault+0xd4/0x220
[223639.948378] [<00000000c4f506ac>] do_exception+0x18c/0x420
[223639.948381] [<00000000c4f50cda>] do_dat_exception+0x2a/0x60
[223639.948382] [<00000000c58ad6a2>] __do_pgm_check+0x132/0x250
[223639.948383] [<00000000c58bbd78>] pgm_check_handler+0x118/0x160
[223819.938812] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[223819.939049] (detected by 1, t=22336501 jiffies, g=11737, q=1164)
[223819.939052] rcu: All QSes seen, last rcu_sched kthread activity 22336498
(4317319034-4294982536), jiffies_till_next_fqs=1, root ->qsmask 0x0
[223819.939172] rcu: rcu_sched kthread starved for 22336498 jiffies! g11737
f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[223819.939284] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM
is now expected behavior.
[223819.939383] rcu: RCU grace-period kthread stack dump:
[223819.939434] task:rcu_sched state:R running task stack: 0 pid:
13 ppid: 2 flags:0x00000000