ubuntu-kernel-tests

ubuntu_kernel_selftests.ftrace: Killed after step #15 on bionic arm64

Bug #1946220 reported by Kleber Sacilotto de Souza on 2021-10-06

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	ubuntu-kernel-tests	New	Undecided	Unassigned

Bug Description

ubuntu_kernel_selftests is aborted/killed after ftrace step #15 on bionic/linux generic 4.15.0-160.168 running on the appleton-kernel node (arm64). I have not spotted this issue on other nodes.

21:39:11 INFO | START ubuntu_kernel_selftests.ftrace ubuntu_kernel_selftests.ftrace timestamp=1632865151 timeout=1800 localtime=Sep 28 21:39:11
21:39:11 DEBUG| Persistent state client._record_indent now set to 2
21:39:11 DEBUG| Persistent state client.unexpected_reboot now set to ('ubuntu_kernel_selftests.ftrace', 'ubuntu_kernel_selftests.ftrace')
21:39:11 DEBUG| Waiting for pid 26487 for 1800 seconds
21:39:11 DEBUG| Running 'sudo sh -c 'echo 1 > /proc/sys/net/ipv4/conf/all/accept_local''
21:39:11 DEBUG| Running 'sudo make -C linux/tools/testing/selftests TARGETS=ftrace run_tests'
21:39:11 DEBUG| [stdout] make: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests'
21:39:11 DEBUG| [stdout] make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
21:39:11 DEBUG| [stdout] make[1]: Nothing to be done for 'all'.
21:39:11 DEBUG| [stdout] make[1]: Leaving directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
21:39:11 DEBUG| [stdout] make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
21:39:11 DEBUG| [stdout] TAP version 13
21:39:11 DEBUG| [stdout] selftests: ftracetest
21:39:11 DEBUG| [stdout] ========================================
21:39:11 DEBUG| [stdout] === Ftrace unit tests ===
21:39:11 DEBUG| [stdout] [1] Basic trace file check [PASS]
21:39:31 DEBUG| [stdout] [2] Basic test for tracers [PASS]
21:39:51 DEBUG| [stdout] [3] Basic trace clock test [PASS]
21:39:51 DEBUG| [stdout] [4] Basic event tracing check [PASS]
21:39:52 DEBUG| [stdout] [5] Snapshot and tracing setting [PASS]
21:39:57 DEBUG| [stdout] [6] event tracing - enable/disable with event level files [PASS]
21:40:02 DEBUG| [stdout] [7] event tracing - restricts events based on pid [PASS]
21:40:06 DEBUG| [stdout] [8] event tracing - enable/disable with subsystem level files [PASS]
21:40:11 DEBUG| [stdout] [9] event tracing - enable/disable with top level files [PASS]
21:40:22 DEBUG| [stdout] [10] ftrace - function graph filters with stack tracer [PASS]
21:40:28 DEBUG| [stdout] [11] ftrace - function graph filters [PASS]
21:40:40 DEBUG| [stdout] [12] ftrace - function pid filters [PASS]
21:40:46 DEBUG| [stdout] [13] ftrace - test for function event triggers [PASS]
21:40:56 DEBUG| [stdout] [14] ftrace - function profiler with function tracing [PASS]
21:40:59 DEBUG| [stdout] [15] ftrace - test reading of set_ftrace_filter [PASS]
-------------------------------------------------------------------------------------------------------
R E S U L T S
-------------------------------------------------------------------------------------------------------

Tags:

Kleber Sacilotto de Souza (kleber-souza) on 2021-10-06

tags:

added: 4.15 arm64 bionic sru-20210927 ubuntu-kernel-selftests

Revision history for this message

Po-Hsu Lin (cypressyew) wrote on 2021-10-07:

When testing this manually with 4.15.0-159 on node appleton-kernel, I can see this hang issue after step 15.

Test output:
ubuntu@appleton-kernel:~/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests$ sudo make run_tests TARGETS=ftrace
make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
make[1]: Nothing to be done for 'all'.
make[1]: Leaving directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
TAP version 13
selftests: ftracetest
========================================
=== Ftrace unit tests ===
[1] Basic trace file check [PASS]
[2] Basic test for tracers [PASS]
[3] Basic trace clock test [PASS]
[4] Basic event tracing check [PASS]
[5] Snapshot and tracing setting [PASS]
[6] event tracing - enable/disable with event level files [PASS]
[7] event tracing - restricts events based on pid [PASS]
[8] event tracing - enable/disable with subsystem level files [PASS]
[9] event tracing - enable/disable with top level files [PASS]
[10] ftrace - function graph filters with stack tracer [PASS]
[11] ftrace - function graph filters [PASS]
[12] ftrace - function pid filters [PASS]
[13] ftrace - test for function event triggers [PASS]
[14] ftrace - function profiler with function tracing [PASS]
[15] ftrace - test reading of set_ftrace_filter [PASS]
[16] ftrace - test for function traceon/off triggers
(stopped here)

syslog output:
Oct 7 10:09:50 appleton-kernel systemd[1]: Started Session 4 of user ubuntu.
Oct 7 10:10:09 appleton-kernel kernel: [ 219.291897] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1
(stopped here)

dmesg output:
[ 219.291897] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1
[ 280.782083] Unable to handle kernel read from unreadable memory at virtual address 00000050
[ 280.790429] Mem abort info:
[ 280.793211] ESR = 0x96000004
[ 280.796287] Exception class = DABT (current EL), IL = 32 bits
[ 280.802225] SET = 0, FnV = 0
[ 280.805274] EA = 0, S1PTW = 0
[ 280.808421] Data abort info:
[ 280.811308] ISV = 0, ISS = 0x00000004
[ 280.815149] CM = 0, WnR = 0
[ 280.818123] user pgtable: 4k pages, 48-bit VAs, pgd = 0000000075661ca7
[ 280.824658] [0000000000000050] *pgd=0000000000000000
[ 280.829628] Internal error: Oops: 96000004 [#1] SMP
(stopped here)

When testing this manually with 4.15.0-159 on node appleton-kernel, I can see this hang issue after step 15.

Test output:
ubuntu@appleton-kernel:~/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests$ sudo make run_tests TARGETS=ftrace
make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
make[1]: Nothing to be done for 'all'.
make[1]: Leaving directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
make[1]: Entering directory '/home/ubuntu/autotest/client/tmp/ubuntu_kernel_selftests/src/linux/tools/testing/selftests/ftrace'
TAP version 13
selftests: ftracetest
========================================
=== Ftrace unit tests ===
[1] Basic trace file check	[PASS]
[2] Basic test for tracers	[PASS]
[3] Basic trace clock test	[PASS]
[4] Basic event tracing check	[PASS]
[5] Snapshot and tracing setting	[PASS]
[6] event tracing - enable/disable with event level files	[PASS]
[7] event tracing - restricts events based on pid	[PASS]
[8] event tracing - enable/disable with subsystem level files	[PASS]
[9] event tracing - enable/disable with top level files	[PASS]
[10] ftrace - function graph filters with stack tracer	[PASS]
[11] ftrace - function graph filters	[PASS]
[12] ftrace - function pid filters	[PASS]
[13] ftrace - test for function event triggers	[PASS]
[14] ftrace - function profiler with function tracing	[PASS]
[15] ftrace - test reading of set_ftrace_filter	[PASS]
[16] ftrace - test for function traceon/off triggers
(stopped here)

syslog output:
Oct  7 10:09:50 appleton-kernel systemd[1]: Started Session 4 of user ubuntu.
Oct  7 10:10:09 appleton-kernel kernel: [  219.291897] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1
(stopped here)

dmesg output:
[  219.291897] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1
[  280.782083] Unable to handle kernel read from unreadable memory at virtual address 00000050
[  280.790429] Mem abort info:
[  280.793211]   ESR = 0x96000004
[  280.796287]   Exception class = DABT (current EL), IL = 32 bits
[  280.802225]   SET = 0, FnV = 0
[  280.805274]   EA = 0, S1PTW = 0
[  280.808421] Data abort info:
[  280.811308]   ISV = 0, ISS = 0x00000004
[  280.815149]   CM = 0, WnR = 0
[  280.818123] user pgtable: 4k pages, 48-bit VAs, pgd = 0000000075661ca7
[  280.824658] [0000000000000050] *pgd=0000000000000000
[  280.829628] Internal error: Oops: 96000004 [#1] SMP
(stopped here)

Revision history for this message

Po-Hsu Lin (cypressyew) wrote on 2021-10-07:

Download full text (4.4 KiB)

Full stack trace from console:
[ 256.441780] Unable to handle kernel read from unreadable memory at virtual address 00000050
[ 256.450170] Mem abort info:
[ 256.441780] Unable to handle k[ 256.452976] ESR = 0x96000004
ernel read from unreadable memory at virtual address 00000050
[ 256.450170] Mem abort info:
[ 256.452976] ESR = 0x96000004
[ 256.470173] Exception class = DABT (current EL), IL = 32 bits
[ 256.476104] SET = 0, FnV = 0
[ 256.479165] EA = 0, S1PTW = 0
[ 256.470173] Exception class [ 256.482320] Data abort info:
= DABT (current EL), IL = 32 bits[ 256.488044] ISV = 0, ISS = 0x00000004

Full stack trace from console:
[  256.441780] Unable to handle kernel read from unreadable memory at virtual address 00000050
[  256.450170] Mem abort info:
[  256.441780] Unable to handle k[  256.452976]   ESR = 0x96000004
ernel read from unreadable memory at virtual address 00000050
[  256.450170] Mem abort info:
[  256.452976]   ESR = 0x96000004
[  256.470173]   Exception class = DABT (current EL), IL = 32 bits
[  256.476104]   SET = 0, FnV = 0
[  256.479165]   EA = 0, S1PTW = 0
[  256.470173]   Exception class [  256.482320] Data abort info:
= DABT (current EL), IL = 32 bits[  256.488044]   ISV = 0, ISS = 0x00000004

[  256.494733]   C[M   =2 506,. WnR = 0
476104]   SET = 0, FnV = 0
[  256.479165]   EA = 0, S1PTW = 0
[  256.482320] Data abort info:
[  256.488044]   ISV = 0, ISS = 0x00000004
[  256.494733]   CM = 0, WnR = 0
[  256.513652] user pgtable: 4k pages, 48-bit VAs, pgd = 00000000cea29530
[  256.520183] [0000000000000050] *pgd=0000000000000000
[  256.513652] user [p g t2a5b6l.525156] Internal error: Oops: 96000004 [#1] SMP
e: 4k pages, 48-bit VAs, pgd = 00000000cea29530
[  256.520183] [0000000000000050] *pgd=0000000000000000
[  256.525156] Internal error: Oops: 96000004 [#1] SMP
[  256.546331] Modules linked in: binfmt_misc ipmi_ssif nls_iso8859_1 joydev input_leds ipmi_si ipmi_devintf ipmi_msghandler shpchp sch_fq_codel ib_iser rdma_cm iw_cm ib_cm iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi ip_tables x_tables autofs4 btrfs zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear mlx5_ib hid_generic usbhid hid ib_core marvell ses enclosure hibmc_drm ttm aes_ce_blk mlx5_core aes_ce_cipher crc32_ce drm_kms_helper ixgbe crct10dif_ce mlxfw ghash_ce syscopyarea devlink sysfillrect sha2_ce sysimgblt sha256_arm64 fb_sys_fops nvme hisi_sas_v2_hw ptp sha1_ce drm hisi_sas_main megaraid_sas mdio nvme_core pps_core libsas ehci_platform hns_dsaf scsi_transport_sas hns_enet_drv hns_mdio hnae aes_neon_bs
[  256.617376]  aes_neon_blk crypto_simd cryptd aes_arm64
[  256.622504] Process swapper/60 (pid: 0, stack limit = 0x00000000fab7ae5e)
[  256.629281] CPU: 60 PID: 0 Comm: swapper/60 Not tainted 4.15.0-159-generic #167-Ubuntu
[  256.637184] Hardware name: Hisilicon D05/BC11SPCD, BIOS 1.50 06/01/2018
[  256.643785] pstate: 00400005 (nzcv daif +PAN -UAO)
[  256.648567] pc : trace_event_raw_event_wbt_timer+0xa0/0xf8
[  256.654039] lr : trace_event_raw_event_wbt_timer+0x90/0xf8
[  256.659510] sp : ffff0000099e3cb0
[  256.662812] x29: ffff0000099e3cb0 x28: 0000000000000282 
[  256.668112] x27: 0000000000000002 x26: ffff0000095a5188 
[  256.673411] x25: ffff801fb06a4800 x24: 0000000000000003 
[  256.678710] x23: 0000000000000000 x22: 0000000000000000 
[  256.684008] x21: ffff801fba1110b0 x20: ffff80afa7356c7c 
[  256.689307] x19: ffff0000095a8000 x18: 0000ffffb05a2a70 
[  256.694605] x17: 0000000000002c80 x16: 0000000000000000 
[  256.699904] x15: 0000000000000000 x14: ffff000008b97c00 
[  256.705203] x13: 0000000000000000 x12: 0000000000000000 
[  256.710501] x11: ffffffffffffffff x10: 0000000000009ad8 
[  256.715800] x9 : 0000000000000c68 x8 : ffff80afb7516400 
[  256.721099] x7 : 0000000000000034 x6 : ffff80afa7356c78 
[  256.726397] x5 : ffff0000099e3c10 x4 : 0000000000000008 
[  256.731696] x3 : 0000000000000020 x2 : 0000000000000000 
[  256.736994] x1 : 000000000000000d x0 : ffff80afa7356c84 
[  256.742294] Call trace:
[  256.744729]  trace_event_raw_event_wbt_timer+0xa0/0xf8
[  256.749854]  wb_timer_fn+0x1f0/0x450
[  256.753417]  blk_stat_timer_fn+0x168/0x180
[  256.757501]  call_timer_fn+0x34/0x178
[  256.761151]  expire_timers+0xc8/0x130
[  256.764800]  run_timer_softirq+0xec/0x1b8
[  256.768797]  __do_softirq+0x134/0x348
[  256.772448]  irq_exit+0xcc/0xe0
[  256.775577]  __handle_domain_irq+0x6c/0xc0
[  256.779660]  gic_handle_irq+0x84/0x180
[  256.783396]  el1_irq+0xe8/0x180
[  256.786524]  arch_cpu_idle+0x30/0x180
[  256.790174]  do_idle+0x138/0x1f0
[  256.793390]  cpu_startup_entry+0x2c/0x40
[  256.797300]  secondary_start_kernel+0x114/0x128
[  256.801820] Code: aa0003f4 b4fffde0 f941cf22 91002000 (f9402841) 
[  256.807972] ---[ end trace 9cd4ceccdf6d5253 ]---
[  256.812577] Kernel panic - not syncing: Fatal exception in interrupt
[  256.818931] SMP: stopping secondary CPUs
[  256.822868] Kernel Offset: disabled
[  256.826344] CPU features: 0x00002008
[  256.829907] Memory Limit: none
[  256.832964] ---[ end Kernel panic - not syncing: Fatal exception in interrupt

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.