While running LTP tracing test case on arm64 the following kernel warnings noticed on linux next tag 20200814.
metadata: git branch: master git repo: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git git commit: 4993e4fe12af2d71b6a3ad16e1fcdc566795fda1 git describe: next-20200814 make_kernelversion: 5.8.0 kernel-config: https://builds.tuxbuild.com/-2CPc32SCi8u5tWn5mkUug/kernel.config
steps to reproduce: # Boot qemu arm64 with trace configs enabled ^. # cd /opt/ltp # ./runltp -f tracing
output log, ------------ ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory [ 54.196774] ------------[ cut here ]------------ [ 54.199689] WARNING: CPU: 2 PID: 1920 at kernel/trace/trace.c:1727 update_max_tr_single.part.0+0xa8/0x148 [ 54.204796] Modules linked in: crct10dif_ce fuse [ 54.207742] CPU: 2 PID: 1920 Comm: cat Not tainted 5.8.0-next-20200814 #1 [ 54.211443] Hardware name: linux,dummy-virt (DT) [ 54.214141] pstate: 80000085 (Nzcv daIf -PAN -UAO BTYPE=--) [ 54.217378] pc : update_max_tr_single.part.0+0xa8/0x148 [ 54.220284] lr : update_max_tr_single.part.0+0x94/0x148 [ 54.223139] sp : ffff800014e9b940 [ 54.225086] x29: ffff800014e9b940 x28: ffff800012197000 [ 54.228235] x27: ffff8000124e9000 x26: 0000000000000001 [ 54.231345] x25: ffff800012545a00 x24: ffff80001001eb7c [ 54.234539] x23: 0000000000000002 x22: ffff800012213980 [ 54.237713] x21: ffff0000e06dc9c0 x20: 0000000000000002 [ 54.240884] x19: ffff800012213980 x18: 0000000000000000 [ 54.244041] x17: 0000000000000000 x16: 0000000000000000 [ 54.247148] x15: 0000000000000000 x14: ffff80001024fcf4 [ 54.250352] x13: ffff80001024fc30 x12: ffff80001024f894 [ 54.253501] x11: ffff80001024d1c8 x10: ffff800010244bc8 [ 54.256671] x9 : ffff0000dec41680 x8 : 0000000000000001 [ 54.259816] x7 : 00000000000002d8 x6 : 0000000000000312 [ 54.262927] x5 : ffff0000fac05200 x4 : ffff0000fad73600 [ 54.266093] x3 : ffff0000fad73400 x2 : 0000000000000002 [ 54.269264] x1 : ffff0000fac05100 x0 : 00000000ffffffea [ 54.272513] Call trace: [ 54.274030] update_max_tr_single.part.0+0xa8/0x148 [ 54.276770] update_max_tr_single+0x1c/0x28 [ 54.279164] check_critical_timing+0x1fc/0x210 [ 54.281680] tracer_preempt_on+0x130/0x178 [ 54.283996] trace_preempt_on+0x34/0x158 [ 54.286173] preempt_count_sub+0xb4/0xf0 [ 54.288447] _raw_spin_unlock+0x24/0x50 [ 54.290607] unmap_page_range+0x5f0/0x868 [ 54.292860] unmap_single_vma+0x90/0x120 [ 54.295046] unmap_vmas+0x78/0xf0 [ 54.296983] unmap_region+0xc0/0x128 [ 54.299043] __do_munmap+0x1bc/0x4e0 [ 54.301118] __vm_munmap+0x78/0xd8 [ 54.303068] __arm64_sys_munmap+0x3c/0x50 [ 54.305373] el0_svc_common.constprop.0+0x7c/0x198 [ 54.308038] do_el0_svc+0x2c/0x98 [ 54.309936] el0_sync_handler+0x9c/0x1b8 [ 54.312168] el0_sync+0x158/0x180 [ 54.314048] ---[ end trace a683c8f878b562c7 ]---
<trim>
[ 104.164380] ------------[ cut here ]------------ [ 104.166499] WARNING: CPU: 0 PID: 701 at kernel/trace/trace.c:5774 __tracing_resize_ring_buffer+0x100/0x118 [ 104.170865] Modules linked in: crct10dif_ce fuse [ 104.173049] CPU: 0 PID: 701 Comm: sh Tainted: G W 5.8.0-next-20200814 #1 [ 104.176715] Hardware name: linux,dummy-virt (DT) [ 104.178864] pstate: 60000005 (nZCv daif -PAN -UAO BTYPE=--) [ 104.181390] pc : __tracing_resize_ring_buffer+0x100/0x118 [ 104.183847] lr : __tracing_resize_ring_buffer+0xfc/0x118 [ 104.186280] sp : ffff80001433bd00 [ 104.187805] x29: ffff80001433bd00 x28: ffff0000e10a49c0 [ 104.190252] x27: 0000000000000000 x26: 0000000000000000 [ 104.192662] x25: 0000000000000000 x24: 0000000000000000 [ 104.195105] x23: 0000000001ccfc00 x22: 0000000001ccfc00 [ 104.197534] x21: 00000000fffffff0 x20: ffffffffffffffff [ 104.199984] x19: ffff800012213980 x18: 0000000000000000 [ 104.202438] x17: 0000000000000000 x16: 0000000000000000 [ 104.204874] x15: 0000000000000000 x14: 0000000000000000 [ 104.207379] x13: 0000000000000003 x12: 0000000000000000 [ 104.209876] x11: 0000000000000001 x10: ffff80001433bc30 [ 104.212289] x9 : ffff800010194980 x8 : ffff0000e10a5480 [ 104.214735] x7 : 0000000000000004 x6 : 000000000000000f [ 104.217154] x5 : 0000000000000003 x4 : 0000000000000000 [ 104.219588] x3 : ffff0000fac05138 x2 : 0000000000000000 [ 104.222036] x1 : ffff0000e10a49c0 x0 : 00000000fffffff0 [ 104.224442] Call trace: [ 104.225628] __tracing_resize_ring_buffer+0x100/0x118 [ 104.227908] tracing_resize_ring_buffer+0x7c/0xb0 [ 104.230069] tracing_entries_write+0x74/0xd0 [ 104.232011] vfs_write+0xf8/0x238 [ 104.233542] ksys_write+0x74/0x100 [ 104.235137] __arm64_sys_write+0x24/0x30 [ 104.236935] el0_svc_common.constprop.0+0x7c/0x198 [ 104.239194] do_el0_svc+0x2c/0x98 [ 104.240761] el0_sync_handler+0x9c/0x1b8 [ 104.242611] el0_sync+0x158/0x180 [ 104.244133] ---[ end trace a683c8f878b562c8 ]---
Reported-by: Naresh Kamboju naresh.kamboju@linaro.org
complete test log, https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200814/testrun...
On Fri, 14 Aug 2020 14:53:36 +0530 Naresh Kamboju naresh.kamboju@linaro.org wrote:
steps to reproduce: # Boot qemu arm64 with trace configs enabled ^. # cd /opt/ltp # ./runltp -f tracing
I don't run ltp, what exactly is this doing?
-- Steve
On Fri, 14 Aug 2020 at 18:11, Steven Rostedt rostedt@goodmis.org wrote:
On Fri, 14 Aug 2020 14:53:36 +0530 Naresh Kamboju naresh.kamboju@linaro.org wrote:
steps to reproduce: # Boot qemu arm64 with trace configs enabled ^. # cd /opt/ltp # ./runltp -f tracing
I don't run ltp, what exactly is this doing?
LTP running ftrace stress testing
Test case : ------------ LOOP=200
# Use up to 10% of free memory free_mem=`cat /proc/meminfo | grep '^MemFree' | awk '{ print $2 }'` cpus=`tst_ncpus`
step=$(( $free_mem / 10 / $LOOP / $cpus ))
if [ $step -eq 0 ]; then step=1 LOOP=50 fi
while true; do new_size=1 i=0 while [ $i -lt $LOOP ]; do echo $new_size > "$TRACING_PATH"/buffer_size_kb ----> Test got failed here new_size=$(( $new_size + $step )) i=$((i + 1)) done
i=0 while [ $i -lt $LOOP ]; do new_size=$(( $new_size - $step )) echo $new_size > "$TRACING_PATH"/buffer_size_kb i=$((i + 1)) done sleep 1 done
test case link, https://raw.githubusercontent.com/linux-test-project/ltp/master/testcases/ke...
ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory [ 90.729590] ------------[ cut here ]------------ [ 90.729882] WARNING: CPU: 1 PID: 2840 at kernel/trace/ring_buffer.c:1273 rb_set_head_page+0x7c/0x108 [ 90.733593] Modules linked in: rfkill snd_soc_hdmi_codec crct10dif_ce adv7511 cec qcom_spmi_temp_alarm rtc_pm8xxx msm snd_soc_msm8916_analog qcom_camss mdt_loader videobuf2_dma_sg v4l2_fwnode videobuf2_memops snd_soc_lpass_apq8016 i2c_qcom_cci drm_kms_helper snd_soc_lpass_cpu qcom_rng snd_soc_msm8916_digital videobuf2_v4l2 snd_soc_lpass_platform snd_soc_apq8016_sbc snd_soc_qcom_common videobuf2_common qrtr ns socinfo display_connector drm rmtfs_mem fuse [ 90.761426] CPU: 1 PID: 2840 Comm: cat Not tainted 5.8.0-next-20200814 #1 [ 90.782653] Hardware name: Qualcomm Technologies, Inc. APQ 8016 SBC (DT) [ 90.789423] pstate: 60000085 (nZCv daIf -PAN -UAO BTYPE=--) [ 90.796165] pc : rb_set_head_page+0x7c/0x108 [ 90.801416] lr : rb_per_cpu_empty+0x18/0x88 [ 90.805922] sp : ffff80001673bc30
File and line number: kernel/trace/ring_buffer.c:1273 rb_set_head_page
static struct buffer_page * rb_set_head_page(struct ring_buffer_per_cpu *cpu_buffer) { struct buffer_page *head; struct buffer_page *page; struct list_head *list; int i;
if (RB_WARN_ON(cpu_buffer, !cpu_buffer->head_page)) return NULL;
/* sanity check */ list = cpu_buffer->pages; if (RB_WARN_ON(cpu_buffer, rb_list_head(list->prev->next) != list)) return NULL;
page = head = cpu_buffer->head_page; /* * It is possible that the writer moves the header behind * where we started, and we miss in one loop. * A second loop should grab the header, but we'll do * three loops just because I'm paranoid. */ for (i = 0; i < 3; i++) { do { if (rb_is_head_page(cpu_buffer, page, page->list.prev)) { cpu_buffer->head_page = page; return page; } rb_inc_page(cpu_buffer, &page); } while (page != head); }
RB_WARN_ON(cpu_buffer, 1); ---> pointing this link number 1273
Full test case output and kernel warning, https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200814/testrun...
- Naresh Kamboju
-- Steve
On Fri, 14 Aug 2020 at 19:57, Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Fri, 14 Aug 2020 at 18:11, Steven Rostedt rostedt@goodmis.org wrote:
On Fri, 14 Aug 2020 14:53:36 +0530 Naresh Kamboju naresh.kamboju@linaro.org wrote:
steps to reproduce: # Boot qemu arm64 with trace configs enabled ^. # cd /opt/ltp # ./runltp -f tracing
FYI, Just for the record the reported issue still exists, These warnings are noticed on arm64 Juno-r2 device with CONFIG_ARM64_64K_PAGES=y
[ 125.616489] WARNING: CPU: 5 PID: 742 at kernel/trace/trace.c:1727 update_max_tr_single.part.0+0xa8/0x148 [ 126.732433] WARNING: CPU: 5 PID: 63 at kernel/trace/ring_buffer.c:1836 rb_update_pages+0x378/0x3a0 [ 127.025416] Internal error: Oops: 96000004 [#1] PREEMPT SMP [ 231.493344] BUG: Bad page state in process sh pfn:98af8
metadata: git branch: master git repo: https://gitlab.com/Linaro/lkft/mirrors/torvalds/linux-mainline git describe: v5.9-rc8-156-gc85fb28b6f99 kernel-config: https://builds.tuxbuild.com/DCkyQvsHwDF-E3sOHqN7SA/kernel.config
Test crash log, -------------------- ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory [ 125.611831] ------------[ cut here ]------------ [ 125.616489] WARNING: CPU: 5 PID: 742 at kernel/trace/trace.c:1727 update_max_tr_single.part.0+0xa8/0x148 [ 125.626057] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 125.633532] CPU: 5 PID: 742 Comm: sh Not tainted 5.9.0-rc8 #1 [ 125.639345] Hardware name: ARM Juno development board (r2) (DT) [ 125.645310] pstate: 80000085 (Nzcv daIf -PAN -UAO BTYPE=--) [ 125.651033] pc : update_max_tr_single.part.0+0xa8/0x148 [ 125.656304] lr : update_max_tr_single.part.0+0x94/0x148 [ 125.661569] sp : ffff80001666f7d0 [ 125.664918] x29: ffff80001666f7d0 x28: ffff8000123f1000 [ 125.670287] x27: ffff800012744000 x26: 0000000000000002 [ 125.675657] x25: ffff8000127e4580 x24: ffff8000100b2060 [ 125.681026] x23: 0000000000000005 x22: ffff800012425880 [ 125.686395] x21: ffff000907113b00 x20: 0000000000000005 [ 125.691764] x19: ffff800012425880 x18: 0000000000000000 [ 125.697133] x17: 0000000000000000 x16: 0000000000000000 [ 125.702501] x15: 0000000000000000 x14: ffff8000102b1f20 [ 125.707870] x13: ffff8000102b0904 x12: ffff8000102c98b0 [ 125.713239] x11: ffff8000102c6eb4 x10: ffff8000102b1ab4 [ 125.718612] x9 : ffff00094056d800 x8 : 0000000000000001 [ 125.723987] x7 : 00000000000004ec x6 : 000000000000013a [ 125.729362] x5 : ffff000940120200 x4 : ffff000940134e00 [ 125.734737] x3 : ffff000940135000 x2 : 0000000000000005 [ 125.740112] x1 : ffff000940120100 x0 : 00000000ffffffea [ 125.745493] Call trace: [ 125.747991] update_max_tr_single.part.0+0xa8/0x148 [ 125.752924] update_max_tr_single+0x1c/0x28 [ 125.757165] check_critical_timing+0x1fc/0x210 [ 125.761663] tracer_hardirqs_on+0x128/0x170 [ 125.765900] trace_hardirqs_on+0x9c/0x250 [ 125.769968] _raw_spin_unlock_irq+0x20/0x58 [ 125.774207] finish_task_switch+0x78/0x258 [ 125.778356] __schedule+0x2d4/0x798 [ 125.781895] schedule+0x50/0x110 [ 125.785174] schedule_preempt_disabled+0x20/0x38 [ 125.789845] __mutex_lock.isra.0+0x184/0x590 [ 125.794168] __mutex_lock_slowpath+0x1c/0x28 [ 125.798490] mutex_lock+0x50/0x60 [ 125.801857] trace_array_get+0x24/0xa0 [ 125.805658] tracing_check_open_get_tr+0x3c/0x60 [ 125.810329] tracing_open_generic_tr+0x20/0x40 [ 125.814830] do_dentry_open+0x134/0x3a0 [ 125.818717] vfs_open+0x34/0x40 [ 125.821910] path_openat+0x85c/0xde0 [ 125.825537] do_filp_open+0x80/0x108 [ 125.829166] do_sys_openat2+0x1ec/0x2a0 [ 125.833054] do_sys_open+0x60/0xa8 [ 125.836507] __arm64_sys_openat+0x2c/0x38 [ 125.840572] do_el0_svc+0x8c/0x1d8 [ 125.844028] el0_sync_handler+0x9c/0x1bc [ 125.848003] el0_sync+0x158/0x180 [ 125.851365] ---[ end trace 6655e5f102a04398 ]--- ftrace_buffer_size_kb.sh: line 33: echo: write error: Cannot allocate memory [ 126.727724] ------------[ cut here ]------------ [ 126.732433] WARNING: CPU: 5 PID: 63 at kernel/trace/ring_buffer.c:1836 rb_update_pages+0x378/0x3a0 [ 126.741455] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 126.748913] CPU: 5 PID: 63 Comm: kworker/5:1 Tainted: G W 5.9.0-rc8 #1 [ 126.756809] Hardware name: ARM Juno development board (r2) (DT) [ 126.762808] Workqueue: events update_pages_handler [ 126.767669] pstate: 60000005 (nZCv daif -PAN -UAO BTYPE=--) [ 126.773305] pc : rb_update_pages+0x378/0x3a0 [ 126.777633] lr : rb_update_pages+0x22c/0x3a0 [ 126.781953] sp : ffff800013b6fd40 [ 126.785320] x29: ffff800013b6fd40 x28: ffff8000123f1000 [ 126.790712] x27: ffff80001300fcd8 x26: ffff0009427b2780 [ 126.796102] x25: 000000000000fff0 x24: ffff000940135088 [ 126.801489] x23: ffff000940135078 x22: ffff0009427b8180 [ 126.806877] x21: fffffffffffffeb4 x20: ffff0009427b2780 [ 126.812267] x19: ffff000940135000 x18: 0000000000000000 [ 126.817654] x17: 0000000000000000 x16: 0000000000000000 [ 126.823041] x15: 0000000000000000 x14: 000002c8000002d8 [ 126.828427] x13: 000002e800000318 x12: 0000000000100000 [ 126.833814] x11: 0000000000100000 x10: ffff800013b6fac0 [ 126.839199] x9 : ffff8000102839b8 x8 : 0000000000000001 [ 126.844587] x7 : 00000000820000ea x6 : 00000000000209c4 [ 126.849974] x5 : ffff800010188abc x4 : ffffffe002309ee0 [ 126.855361] x3 : ffff0009427b2780 x2 : 0000000000000000 [ 126.860750] x1 : 0000000000000001 x0 : ffff000940120108 [ 126.866143] Call trace: [ 126.868650] rb_update_pages+0x378/0x3a0 [ 126.872633] update_pages_handler+0x1c/0x38 [ 126.876884] process_one_work+0x1c8/0x488 [ 126.880961] worker_thread+0x54/0x428 [ 126.884693] kthread+0x120/0x158 [ 126.887990] ret_from_fork+0x10/0x30 [ 126.891628] ---[ end trace 6655e5f102a04399 ]--- [ 126.972927] Unable to handle kernel paging request at virtual address 00646c2f62696c2c [ 126.982191] Mem abort info: [ 126.985172] ESR = 0x96000004 [ 126.989355] EC = 0x25: DABT (current EL), IL = 32 bits [ 126.997080] SET = 0, FnV = 0 [ 127.001549] EA = 0, S1PTW = 0 [ 127.005144] Data abort info: [ 127.009065] ISV = 0, ISS = 0x00000004 [ 127.013931] CM = 0, WnR = 0 [ 127.017086] [00646c2f62696c2c] address between user and kernel address ranges [ 127.025416] Internal error: Oops: 96000004 [#1] PREEMPT SMP [ 127.031066] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 127.038523] CPU: 3 PID: 744 Comm: sh Tainted: G W 5.9.0-rc8 #1 [ 127.045717] Hardware name: ARM Juno development board (r2) (DT) [ 127.051695] pstate: 00000005 (nzcv daif -PAN -UAO BTYPE=--) [ 127.057335] pc : rb_check_pages+0x40/0x210 [ 127.061488] lr : rb_check_pages+0x20/0x210 [ 127.065636] sp : ffff8000166afc40 [ 127.068999] x29: ffff8000166afc40 x28: ffff000907111d80 [ 127.074382] x27: ffff8000124258a8 x26: 0000000000000143 [ 127.079765] x25: 0000000000000000 x24: ffff8000123f4420 [ 127.085181] x23: ffff000940120138 x22: ffff000940120110 [ 127.090576] x21: ffff000940120100 x20: 000000000142ebd0 [ 127.095960] x19: ffff000940120108 x18: 0000000000000000 [ 127.101344] x17: 0000000000000000 x16: 0000000000000000 [ 127.106727] x15: 000000000000037f x14: 0000000000000401 [ 127.112110] x13: 0000000000000003 x12: 0000000000000000 [ 127.117493] x11: 0000000000000005 x10: ffff000940134a10 [ 127.122876] x9 : 0000000000000000 x8 : ffff00090b4ce600 [ 127.128261] x7 : ffff0009427bd200 x6 : ffff000940135000 [ 127.133667] x5 : 0000000000000003 x4 : ffff0009427bb780 [ 127.139064] x3 : ffff0009427bb780 x2 : 2d646c2f62696c2c [ 127.144448] x1 : 2d646c2f62696c2c x0 : ffff0009427bd200 [ 127.149834] Call trace: [ 127.152337] rb_check_pages+0x40/0x210 [ 127.156143] ring_buffer_resize+0x324/0x4e0 [ 127.160388] resize_buffer_duplicate_size.isra.0+0x74/0x130 [ 127.166023] __tracing_resize_ring_buffer+0xfc/0x118 [ 127.171051] tracing_resize_ring_buffer+0x7c/0xb0 [ 127.175816] tracing_entries_write+0x74/0xd0 [ 127.180226] vfs_write+0xf8/0x238 [ 127.183597] ksys_write+0x74/0x100 [ 127.187054] __arm64_sys_write+0x24/0x30 [ 127.191036] do_el0_svc+0x8c/0x1d8 [ 127.194496] el0_sync_handler+0x9c/0x1bc [ 127.198474] el0_sync+0x158/0x180 [ 127.201852] Code: f9401cc0 f9400002 eb02001f 54000100 (f9400041) [ 127.208022] ---[ end trace 6655e5f102a0439a ]--- Oct 6 21:53:20 juno daemon.info haveged: haveged: Stopping due to signal 15 [ 190.436243] ------------[ cut here ]------------ [ 190.440892] WARNING: CPU: 2 PID: 2783 at kernel/trace/ring_buffer.c:4134 rb_get_reader_page+0x264/0x2a8 [ 190.450315] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 190.457663] CPU: 2 PID: 2783 Comm: cat Tainted: G D W 5.9.0-rc8 #1 [ 190.464981] Hardware name: ARM Juno development board (r2) (DT) [ 190.470910] pstate: 60000085 (nZCv daIf -PAN -UAO BTYPE=--) [ 190.476491] pc : rb_get_reader_page+0x264/0x2a8 [ 190.481026] lr : rb_get_reader_page+0x148/0x2a8 [ 190.485559] sp : ffff800018e8fba0 [ 190.488874] x29: ffff800018e8fba0 x28: ffff00090b1affe8 [ 190.494192] x27: ffff000940135004 x26: 0000000000000060 [ 190.499511] x25: ffff000901a21d80 x24: ffff800018e8fd18 [ 190.504829] x23: ffff800018e8fd20 x22: ffff0009427b8b00 [ 190.510147] x21: 0000000000000080 x20: 0000000000000080 [ 190.515470] x19: ffff000940135000 x18: 0000000000000001 [ 190.520796] x17: 0000000000000000 x16: 0000000000000000 [ 190.526125] x15: ffff000901a22200 x14: ffffffffffffffff [ 190.531463] x13: ffff000948d600b8 x12: 0000000000000018 [ 190.536803] x11: 0101010101010101 x10: ffff800018e8fc00 [ 190.542143] x9 : 0000000000000000 x8 : 0000000000000001 [ 190.547483] x7 : 0000000000000000 x6 : ffff0009401350b8 [ 190.552823] x5 : 000000000001ccc7 x4 : ffff0009427b8c00 [ 190.558163] x3 : ffff0009427b3400 x2 : 0000000000000000 [ 190.563502] x1 : 0000000000100003 x0 : ffff000940120108 [ 190.568843] Call trace: [ 190.571336] rb_get_reader_page+0x264/0x2a8 [ 190.575541] rb_buffer_peek+0x34/0x168 [ 190.579311] ring_buffer_peek+0x94/0x1b8 [ 190.583256] peek_next_entry+0xa0/0xc8 [ 190.587026] __find_next_entry+0xc4/0x1c0 [ 190.591057] trace_find_next_entry_inc+0x34/0x98 [ 190.595696] tracing_read_pipe+0x190/0x308 [ 190.599815] vfs_read+0xb4/0x1e0 [ 190.603061] ksys_read+0x74/0x100 [ 190.606420] __arm64_sys_read+0x24/0x30 [ 190.610278] do_el0_svc+0x8c/0x1d8 [ 190.613700] el0_sync_handler+0x9c/0x1bc [ 190.617642] el0_sync+0x158/0x180 [ 190.620974] ---[ end trace 6655e5f102a0439b ]--- ftrace-stress-test 1 TINFO: killing 721 [ 231.493344] BUG: Bad page state in process sh pfn:98af8 [ 231.498686] page:0000000044ba8ba8 refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98af8 [ 231.508100] flags: 0x2ffff00000000000() [ 231.511948] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 231.519710] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 231.527467] page dumped because: nonzero _refcount [ 231.532265] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 231.539653] CPU: 4 PID: 7037 Comm: sh Tainted: G D W 5.9.0-rc8 #1 [ 231.546930] Hardware name: ARM Juno development board (r2) (DT) [ 231.552893] Call trace: [ 231.555403] dump_backtrace+0x0/0x1e0 [ 231.559107] show_stack+0x20/0x30 [ 231.562466] dump_stack+0xe8/0x15c [ 231.565911] bad_page+0xd4/0x100 [ 231.569182] check_new_page_bad+0x84/0xa0 [ 231.573307] get_page_from_freelist+0x12e0/0x19c0 [ 231.578060] __alloc_pages_nodemask+0x164/0x370 [ 231.582638] alloc_pages_current+0x90/0x108 [ 231.586873] skb_page_frag_refill+0xa8/0xf8 [ 231.591103] sk_page_frag_refill+0x28/0x90 [ 231.595247] tcp_sendmsg_locked+0x338/0xc00 [ 231.599477] tcp_sendmsg+0x40/0x68 [ 231.602925] inet_sendmsg+0x4c/0x78 [ 231.606467] sock_sendmsg+0x24/0x40 [ 231.610002] xprt_sock_sendmsg+0xe4/0x2c0 [ 231.614059] xs_tcp_send_request+0xd0/0x1c8 [ 231.618289] xprt_transmit+0x1ac/0x4b0 [ 231.622085] call_transmit+0x9c/0xb8 [ 231.625706] __rpc_execute+0x8c/0x560 [ 231.629414] rpc_execute+0x150/0x168 [ 231.633034] rpc_run_task+0x15c/0x1c0 [ 231.636740] rpc_call_sync+0x5c/0xb8 [ 231.640369] nfs3_rpc_wrapper+0x58/0xd8 [ 231.644252] nfs3_proc_getattr+0x74/0xa0 [ 231.648222] __nfs_revalidate_inode+0x14c/0x3c0 [ 231.652806] nfs_lookup_verify_inode+0x84/0xa8 [ 231.657299] nfs_do_lookup_revalidate+0x168/0x428 [ 231.662051] __nfs_lookup_revalidate+0x84/0xb0 [ 231.666543] nfs_lookup_revalidate+0x20/0x30 [ 231.670860] lookup_fast+0x180/0x190 [ 231.674481] path_openat+0x110/0xde0 [ 231.678102] do_filp_open+0x80/0x108 [ 231.681723] do_open_execat+0x78/0x1e0 [ 231.685519] bprm_execve+0x154/0x668 [ 231.689140] do_execveat_common+0x164/0x1b0 [ 231.693371] __arm64_sys_execve+0x40/0x58 [ 231.697428] do_el0_svc+0x8c/0x1d8 [ 231.700876] el0_sync_handler+0x9c/0x1bc [ 231.704844] el0_sync+0x158/0x180 [ 232.169547] BUG: Bad page state in process sh pfn:98af9 [ 232.174898] page:000000008ece15a1 refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98af9 [ 232.184326] flags: 0x2ffff00000000000() [ 232.188188] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 232.195963] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 232.203736] page dumped because: nonzero _refcount [ 232.208550] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 232.215925] CPU: 1 PID: 7059 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 232.223176] Hardware name: ARM Juno development board (r2) (DT) [ 232.229122] Call trace: [ 232.231594] dump_backtrace+0x0/0x1e0 [ 232.235280] show_stack+0x20/0x30 [ 232.238620] dump_stack+0xe8/0x15c [ 232.242047] bad_page+0xd4/0x100 [ 232.245298] check_new_page_bad+0x84/0xa0 [ 232.249333] get_page_from_freelist+0x12e0/0x19c0 [ 232.254062] __alloc_pages_nodemask+0x164/0x370 [ 232.258619] alloc_pages_current+0x90/0x108 [ 232.262828] __get_free_pages+0x1c/0x58 [ 232.266688] tlb_remove_table+0x84/0x118 [ 232.270636] free_pgd_range+0x198/0x340 [ 232.274497] free_pgtables+0x100/0x140 [ 232.278269] exit_mmap+0xe4/0x188 [ 232.281607] mmput+0x8c/0x160 [ 232.284598] begin_new_exec+0x2d0/0xcf0 [ 232.288460] load_elf_binary+0x3a4/0x16b8 [ 232.292495] bprm_execve+0x290/0x668 [ 232.296095] do_execveat_common+0x164/0x1b0 [ 232.300304] __arm64_sys_execve+0x40/0x58 [ 232.304340] do_el0_svc+0x8c/0x1d8 [ 232.307766] el0_sync_handler+0x9c/0x1bc [ 232.311713] el0_sync+0x158/0x180 [ 235.802764] BUG: Bad page state in process sh pfn:98afa [ 235.808108] page:0000000082dda10f refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98afa [ 235.817524] flags: 0x2ffff00000000000() [ 235.821372] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 235.829133] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 235.836890] page dumped because: nonzero _refcount [ 235.841688] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 235.849031] CPU: 5 PID: 7166 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 235.856266] Hardware name: ARM Juno development board (r2) (DT) [ 235.862199] Call trace: [ 235.864656] dump_backtrace+0x0/0x1e0 [ 235.868370] show_stack+0x20/0x30 [ 235.871709] dump_stack+0xe8/0x15c [ 235.875136] bad_page+0xd4/0x100 [ 235.878387] check_new_page_bad+0x84/0xa0 [ 235.882431] get_page_from_freelist+0x12e0/0x19c0 [ 235.887176] __alloc_pages_nodemask+0x164/0x370 [ 235.891752] alloc_pages_current+0x90/0x108 [ 235.895983] skb_page_frag_refill+0xa8/0xf8 [ 235.900210] sk_page_frag_refill+0x28/0x90 [ 235.904352] tcp_sendmsg_locked+0x338/0xc00 [ 235.908651] tcp_sendmsg+0x40/0x68 [ 235.912100] inet_sendmsg+0x4c/0x78 [ 235.915643] sock_sendmsg+0x24/0x40 [ 235.919178] xprt_sock_sendmsg+0xe4/0x2c0 [ 235.923234] xs_tcp_send_request+0xd0/0x1c8 [ 235.927465] xprt_transmit+0x1ac/0x4b0 [ 235.931262] call_transmit+0x9c/0xb8 [ 235.934883] __rpc_execute+0x8c/0x560 [ 235.938591] rpc_execute+0x150/0x168 [ 235.942211] rpc_run_task+0x15c/0x1c0 [ 235.945918] rpc_call_sync+0x5c/0xb8 [ 235.949547] nfs3_rpc_wrapper+0x58/0xd8 [ 235.953429] nfs3_proc_getattr+0x74/0xa0 [ 235.957400] __nfs_revalidate_inode+0x14c/0x3c0 [ 235.961984] nfs_lookup_verify_inode+0x84/0xa8 [ 235.966478] nfs_do_lookup_revalidate+0x168/0x428 [ 235.971231] __nfs_lookup_revalidate+0x84/0xb0 [ 235.975722] nfs_lookup_revalidate+0x20/0x30 [ 235.980040] lookup_fast+0x180/0x190 [ 235.983660] path_openat+0x110/0xde0 [ 235.987281] do_filp_open+0x80/0x108 [ 235.990903] do_open_execat+0x78/0x1e0 [ 235.994698] bprm_execve+0x154/0x668 [ 235.998320] do_execveat_common+0x164/0x1b0 [ 236.002551] __arm64_sys_execve+0x40/0x58 [ 236.006608] do_el0_svc+0x8c/0x1d8 [ 236.010056] el0_sync_handler+0x9c/0x1bc [ 236.014025] el0_sync+0x158/0x180 [ 238.715995] BUG: Bad page state in process cat pfn:98afb [ 238.721438] page:000000002ed6a442 refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98afb [ 238.730868] flags: 0x2ffff00000000000() [ 238.734731] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 238.742509] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 238.750282] page dumped because: nonzero _refcount [ 238.755095] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 238.762478] CPU: 4 PID: 7218 Comm: cat Tainted: G B D W 5.9.0-rc8 #1 [ 238.769816] Hardware name: ARM Juno development board (r2) (DT) [ 238.775762] Call trace: [ 238.778236] dump_backtrace+0x0/0x1e0 [ 238.781923] show_stack+0x20/0x30 [ 238.785265] dump_stack+0xe8/0x15c [ 238.788694] bad_page+0xd4/0x100 [ 238.791947] check_new_page_bad+0x84/0xa0 [ 238.795984] get_page_from_freelist+0x12e0/0x19c0 [ 238.800715] __alloc_pages_nodemask+0x164/0x370 [ 238.805274] alloc_pages_current+0x90/0x108 [ 238.809484] __get_free_pages+0x1c/0x58 [ 238.813345] tlb_remove_table+0x84/0x118 [ 238.817295] free_pgd_range+0x198/0x340 [ 238.821157] free_pgtables+0x100/0x140 [ 238.824931] exit_mmap+0xe4/0x188 [ 238.828271] mmput+0x8c/0x160 [ 238.831263] do_exit+0x2ac/0x9f8 [ 238.834516] do_group_exit+0x4c/0xa8 [ 238.838117] __wake_up_parent+0x0/0x38 [ 238.841895] do_el0_svc+0x8c/0x1d8 [ 238.845323] el0_sync_handler+0x9c/0x1bc [ 238.849271] el0_sync+0x158/0x180 [ 247.784141] BUG: Bad page state in process sh pfn:98afc [ 247.789495] page:000000004431112a refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98afc [ 247.798921] flags: 0x2ffff00000000000() [ 247.802782] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 247.810556] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 247.818325] page dumped because: nonzero _refcount [ 247.823135] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 247.830498] CPU: 5 PID: 736 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 247.837658] Hardware name: ARM Juno development board (r2) (DT) [ 247.843601] Call trace: [ 247.846070] dump_backtrace+0x0/0x1e0 [ 247.849753] show_stack+0x20/0x30 [ 247.853089] dump_stack+0xe8/0x15c [ 247.856512] bad_page+0xd4/0x100 [ 247.859761] check_new_page_bad+0x84/0xa0 [ 247.863792] get_page_from_freelist+0x12e0/0x19c0 [ 247.868518] __alloc_pages_nodemask+0x164/0x370 [ 247.873072] alloc_pages_current+0x90/0x108 [ 247.877277] __vmalloc_node_range+0x1e0/0x2b0 [ 247.881657] copy_process+0x2c8/0x1710 [ 247.885425] _do_fork+0x98/0x488 [ 247.888672] __do_sys_clone+0x58/0x80 [ 247.892354] __arm64_sys_clone+0x28/0x38 [ 247.896300] do_el0_svc+0x8c/0x1d8 [ 247.899722] el0_sync_handler+0x9c/0x1bc [ 247.903666] el0_sync+0x158/0x180 [ 247.907003] BUG: Bad page state in process sh pfn:98afd [ 247.912344] page:000000007895a095 refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98afd [ 247.921808] flags: 0x2ffff00000000000() [ 247.925667] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 247.933477] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 247.941246] page dumped because: nonzero _refcount [ 247.946055] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 247.953415] CPU: 4 PID: 7520 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 247.960662] Hardware name: ARM Juno development board (r2) (DT) [ 247.966603] Call trace: [ 247.969068] dump_backtrace+0x0/0x1e0 [ 247.972750] show_stack+0x20/0x30 [ 247.976086] dump_stack+0xe8/0x15c [ 247.979509] bad_page+0xd4/0x100 [ 247.982757] check_new_page_bad+0x84/0xa0 [ 247.986787] get_page_from_freelist+0x12e0/0x19c0 [ 247.991513] __alloc_pages_nodemask+0x164/0x370 [ 247.996066] alloc_pages_current+0x90/0x108 [ 248.000275] skb_page_frag_refill+0xa8/0xf8 [ 248.004479] sk_page_frag_refill+0x28/0x90 [ 248.008598] tcp_sendmsg_locked+0x338/0xc00 [ 248.012803] tcp_sendmsg+0x40/0x68 [ 248.016225] inet_sendmsg+0x4c/0x78 [ 248.019742] sock_sendmsg+0x24/0x40 [ 248.023252] xprt_sock_sendmsg+0xe4/0x2c0 [ 248.027283] xs_tcp_send_request+0xd0/0x1c8 [ 248.031487] xprt_transmit+0x1ac/0x4b0 [ 248.035258] call_transmit+0x9c/0xb8 [ 248.038854] __rpc_execute+0x8c/0x560 [ 248.042536] rpc_execute+0x150/0x168 [ 248.046130] rpc_run_task+0x15c/0x1c0 [ 248.049811] rpc_call_sync+0x5c/0xb8 [ 248.053415] nfs3_rpc_wrapper+0x58/0xd8 [ 248.057272] nfs3_proc_getattr+0x74/0xa0 [ 248.061217] __nfs_revalidate_inode+0x14c/0x3c0 [ 248.065775] nfs_lookup_verify_inode+0x84/0xa8 [ 248.070244] nfs_do_lookup_revalidate+0x168/0x428 [ 248.074971] __nfs_lookup_revalidate+0x84/0xb0 [ 248.079437] nfs_lookup_revalidate+0x20/0x30 [ 248.083729] lookup_fast+0x180/0x190 [ 248.087324] path_openat+0x110/0xde0 [ 248.090919] do_filp_open+0x80/0x108 [ 248.094516] do_open_execat+0x78/0x1e0 [ 248.098286] bprm_execve+0x154/0x668 [ 248.101882] do_execveat_common+0x164/0x1b0 [ 248.106087] __arm64_sys_execve+0x40/0x58 [ 248.110119] do_el0_svc+0x8c/0x1d8 [ 248.113541] el0_sync_handler+0x9c/0x1bc [ 248.117484] el0_sync+0x158/0x180 [ 248.120818] BUG: Bad page state in process sh pfn:98afe [ 248.126154] page:0000000029e006c6 refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98afe [ 248.135578] flags: 0x2ffff00000000000() [ 248.139435] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 248.147208] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 248.154977] page dumped because: nonzero _refcount [ 248.159786] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 248.167142] CPU: 4 PID: 7520 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 248.174389] Hardware name: ARM Juno development board (r2) (DT) [ 248.180330] Call trace: [ 248.182793] dump_backtrace+0x0/0x1e0 [ 248.186475] show_stack+0x20/0x30 [ 248.189809] dump_stack+0xe8/0x15c [ 248.193231] bad_page+0xd4/0x100 [ 248.196479] check_new_page_bad+0x84/0xa0 [ 248.200509] get_page_from_freelist+0x12e0/0x19c0 [ 248.205235] __alloc_pages_nodemask+0x164/0x370 [ 248.209787] alloc_pages_current+0x90/0x108 [ 248.213991] skb_page_frag_refill+0xa8/0xf8 [ 248.218195] sk_page_frag_refill+0x28/0x90 [ 248.222313] tcp_sendmsg_locked+0x338/0xc00 [ 248.226518] tcp_sendmsg+0x40/0x68 [ 248.229940] inet_sendmsg+0x4c/0x78 [ 248.233450] sock_sendmsg+0x24/0x40 [ 248.236958] xprt_sock_sendmsg+0xe4/0x2c0 [ 248.240989] xs_tcp_send_request+0xd0/0x1c8 [ 248.245193] xprt_transmit+0x1ac/0x4b0 [ 248.248963] call_transmit+0x9c/0xb8 [ 248.252558] __rpc_execute+0x8c/0x560 [ 248.256240] rpc_execute+0x150/0x168 [ 248.259835] rpc_run_task+0x15c/0x1c0 [ 248.263516] rpc_call_sync+0x5c/0xb8 [ 248.267113] nfs3_rpc_wrapper+0x58/0xd8 [ 248.270970] nfs3_proc_getattr+0x74/0xa0 [ 248.274913] __nfs_revalidate_inode+0x14c/0x3c0 [ 248.279466] nfs_lookup_verify_inode+0x84/0xa8 [ 248.283933] nfs_do_lookup_revalidate+0x168/0x428 [ 248.288660] __nfs_lookup_revalidate+0x84/0xb0 [ 248.293126] nfs_lookup_revalidate+0x20/0x30 [ 248.297418] lookup_fast+0x180/0x190 [ 248.301012] path_openat+0x110/0xde0 [ 248.304608] do_filp_open+0x80/0x108 [ 248.308204] do_open_execat+0x78/0x1e0 [ 248.311974] bprm_execve+0x154/0x668 [ 248.315570] do_execveat_common+0x164/0x1b0 [ 248.319775] __arm64_sys_execve+0x40/0x58 [ 248.323806] do_el0_svc+0x8c/0x1d8 [ 248.327228] el0_sync_handler+0x9c/0x1bc [ 248.331171] el0_sync+0x158/0x180 [ 248.334504] BUG: Bad page state in process sh pfn:98aff [ 248.339840] page:0000000011eee57f refcount:-1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x98aff [ 248.349264] flags: 0x2ffff00000000000() [ 248.353121] raw: 2ffff00000000000 dead000000000100 dead000000000122 0000000000000000 [ 248.360894] raw: 0000000000000000 0000000000000000 ffffffffffffffff 0000000000000000 [ 248.368663] page dumped because: nonzero _refcount [ 248.373471] Modules linked in: tda998x cec drm_kms_helper drm crct10dif_ce fuse [ 248.380827] CPU: 4 PID: 7520 Comm: sh Tainted: G B D W 5.9.0-rc8 #1 [ 248.388074] Hardware name: ARM Juno development board (r2) (DT) [ 248.394014] Call trace: [ 248.396478] dump_backtrace+0x0/0x1e0 [ 248.400159] show_stack+0x20/0x30 [ 248.403493] dump_stack+0xe8/0x15c [ 248.406915] bad_page+0xd4/0x100 [ 248.410163] check_new_page_bad+0x84/0xa0 [ 248.414193] get_page_from_freelist+0x12e0/0x19c0 [ 248.418918] __alloc_pages_nodemask+0x164/0x370 [ 248.423470] alloc_pages_current+0x90/0x108 [ 248.427676] skb_page_frag_refill+0xa8/0xf8 [ 248.431880] sk_page_frag_refill+0x28/0x90 [ 248.435998] tcp_sendmsg_locked+0x338/0xc00 [ 248.440202] tcp_sendmsg+0x40/0x68 [ 248.443624] inet_sendmsg+0x4c/0x78 [ 248.447133] sock_sendmsg+0x24/0x40 [ 248.450642] xprt_sock_sendmsg+0xe4/0x2c0 [ 248.454673] xs_tcp_send_request+0xd0/0x1c8 [ 248.458876] xprt_transmit+0x1ac/0x4b0 [ 248.462647] call_transmit+0x9c/0xb8 [ 248.466241] __rpc_execute+0x8c/0x560 [ 248.469923] rpc_execute+0x150/0x168 [ 248.473517] rpc_run_task+0x15c/0x1c0 [ 248.477199] rpc_call_sync+0x5c/0xb8 [ 248.480796] nfs3_rpc_wrapper+0x58/0xd8 [ 248.484652] nfs3_proc_getattr+0x74/0xa0 [ 248.488595] __nfs_revalidate_inode+0x14c/0x3c0 [ 248.493149] nfs_lookup_verify_inode+0x84/0xa8 [ 248.497616] nfs_do_lookup_revalidate+0x168/0x428 [ 248.502343] __nfs_lookup_revalidate+0x84/0xb0 [ 248.506809] nfs_lookup_revalidate+0x20/0x30 [ 248.511100] lookup_fast+0x180/0x190 [ 248.514695] path_openat+0x110/0xde0 [ 248.518290] do_filp_open+0x80/0x108 [ 248.521887] do_open_execat+0x78/0x1e0 [ 248.525657] bprm_execve+0x154/0x668 [ 248.529253] do_execveat_common+0x164/0x1b0 [ 248.533458] __arm64_sys_execve+0x40/0x58 [ 248.537489] do_el0_svc+0x8c/0x1d8 [ 248.540912] el0_sync_handler+0x9c/0x1bc [ 248.544854] el0_sync+0x158/0x180
full test log, https://qa-reports.linaro.org/lkft/linux-mainline-master/build/v5.9-rc8-156-...
-
Naresh Kamboju -
Steven Rostedt