Re: [PATCH] tracing/timerlat: Move hrtimer_init to timerlat_fd open()

Daniel Bristot de Oliveira
2024-02-01T16:02:59Z

On 2/1/24 16:44, Greg KH wrote:
> On Thu, Feb 01, 2024 at 04:13:39PM +0100, Daniel Bristot de Oliveira wrote:
>> Currently, the timerlat's hrtimer is initialized at the first read of
>> timerlat_fd, and destroyed at close(). It works, but it causes an error
>> if the user program open() and close() the file without reading.
>
> What error exactly happens? Userspace, or the kernel crashes?

sorry, kernel crash:

# echo NO_OSNOISE_WORKLOAD > /sys/kernel/debug/tracing/osnoise/options
# echo timerlat > /sys/kernel/debug/tracing/current_tracer

# cat ./timerlat_load.py
#!/usr/bin/env python3

timerlat_fd = open("/sys/kernel/tracing/osnoise/per_cpu/cpu0/timerlat_fd", 'r')
timerlat_fd.close();

# ./taskset -c 0 ./timerlat_load.py
<BOOM>

[ 6401.611374] BUG: kernel NULL pointer dereference, address: 0000000000000010
[ 6401.611786] #PF: supervisor read access in kernel mode
[ 6401.612081] #PF: error_code(0x0000) - not-present page
[ 6401.612376] PGD 0 P4D 0
[ 6401.612495] Oops: 0000 [#1] PREEMPT SMP NOPTI
[ 6401.612690] CPU: 1 PID: 2673 Comm: python3 Not tainted 6.6.13-200.fc39.x86_64 #1
[ 6401.613011] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-1.fc39 04/01/2014
[ 6401.613379] RIP: 0010:hrtimer_active+0xd/0x50
[ 6401.613577] Code: 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa 0f 1f 44 00 00 48 8b 57 30 <8b> 42 10 a8 01 74 09 f3 90 8b 42 10 a8 01 75 f7 80 7f 38 00 75 1d
[ 6401.614374] RSP: 0018:ffffb031009b7e10 EFLAGS: 00010286
[ 6401.614604] RAX: 000000000002db00 RBX: ffff9118f786db08 RCX: 0000000000000000
[ 6401.614914] RDX: 0000000000000000 RSI: ffff9117a0e64400 RDI: ffff9118f786db08
[ 6401.615225] RBP: ffff9118f786db80 R08: ffff9117a0ddd420 R09: ffff9117804d4f70
[ 6401.615534] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9118f786db08
[ 6401.615846] R13: ffff91178fdd5e20 R14: ffff9117840978c0 R15: 0000000000000000
[ 6401.616157] FS: 00007f2ffbab1740(0000) GS:ffff9118f7840000(0000) knlGS:0000000000000000
[ 6401.616508] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6401.616765] CR2: 0000000000000010 CR3: 00000001b402e000 CR4: 0000000000750ee0
[ 6401.617075] PKRU: 55555554
[ 6401.617197] Call Trace:
[ 6401.617309] <TASK>
[ 6401.617407] ? __die+0x23/0x70
[ 6401.617548] ? page_fault_oops+0x171/0x4e0
[ 6401.617983] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.618389] ? avc_has_extended_perms+0x237/0x520
[ 6401.618800] ? exc_page_fault+0x7f/0x180
[ 6401.619176] ? asm_exc_page_fault+0x26/0x30
[ 6401.619563] ? hrtimer_active+0xd/0x50
[ 6401.619926] hrtimer_cancel+0x15/0x40
[ 6401.620286] timerlat_fd_release+0x48/0xe0
[ 6401.620666] __fput+0xf5/0x290
[ 6401.621004] __x64_sys_close+0x3d/0x80
[ 6401.621370] do_syscall_64+0x60/0x90
[ 6401.621730] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.622129] ? __x64_sys_ioctl+0x72/0xd0
[ 6401.622503] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.622902] ? syscall_exit_to_user_mode+0x2b/0x40
[ 6401.623309] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.623703] ? do_syscall_64+0x6c/0x90
[ 6401.624063] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.624457] ? exit_to_user_mode_prepare+0x142/0x1f0
[ 6401.624868] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.625262] ? syscall_exit_to_user_mode+0x2b/0x40
[ 6401.625663] ? srso_alias_return_thunk+0x5/0x7f
[ 6401.626051] ? do_syscall_64+0x6c/0x90
[ 6401.626404] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 6401.626810] RIP: 0033:0x7f2ffb321594
[ 6401.627164] Code: 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 80 3d d5 cd 0d 00 00 74 13 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 3c c3 0f 1f 00 55 48 89 e5 48 83 ec 10 89 7d
[ 6401.628345] RSP: 002b:00007ffe8d8eef18 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[ 6401.628867] RAX: ffffffffffffffda RBX: 00007f2ffba4e668 RCX: 00007f2ffb321594
[ 6401.629372] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003
[ 6401.629879] RBP: 00007ffe8d8eef40 R08: 0000000000000000 R09: 0000000000000000
[ 6401.630384] R10: 55c926e3167eae79 R11: 0000000000000202 R12: 0000000000000003
[ 6401.630889] R13: 00007ffe8d8ef030 R14: 0000000000000000 R15: 00007f2ffba4e668
[ 6401.631394] </TASK>
[ 6401.631691] Modules linked in: tls nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill ip_set nf_tables nfnetlink qrtr sunrpc pktcdvd intel_rapl_msr snd_hda_codec_generic intel_rapl_common ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec snd_hda_core snd_hwdep snd_pcm kvm_amd iTCO_wdt snd_timer intel_pmc_bxt ccp joydev iTCO_vendor_support kvm irqbypass i2c_i801 snd i2c_smbus soundcore lpc_ich virtio_balloon loop zram crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic ghash_clmulni_intel sha512_ssse3 sha256_ssse3 sha1_ssse3 virtio_net virtio_gpu virtio_console virtio_blk net_failover failover virtio_dma_buf serio_raw scsi_dh_rdac scsi_dh_emc scsi_dh_alua fuse dm_multipath qemu_fw_cfg
[ 6401.636126] CR2: 0000000000000010
[ 6401.636482] ---[ end trace 0000000000000000 ]---
[ 6401.636891] RIP: 0010:hrtimer_active+0xd/0x50
[ 6401.637288] Code: 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa 0f 1f 44 00 00 48 8b 57 30 <8b> 42 10 a8 01 74 09 f3 90 8b 42 10 a8 01 75 f7 80 7f 38 00 75 1d
[ 6401.638507] RSP: 0018:ffffb031009b7e10 EFLAGS: 00010286
[ 6401.638951] RAX: 000000000002db00 RBX: ffff9118f786db08 RCX: 0000000000000000
[ 6401.639478] RDX: 0000000000000000 RSI: ffff9117a0e64400 RDI: ffff9118f786db08
[ 6401.640005] RBP: ffff9118f786db80 R08: ffff9117a0ddd420 R09: ffff9117804d4f70
[ 6401.640535] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9118f786db08
[ 6401.641067] R13: ffff91178fdd5e20 R14: ffff9117840978c0 R15: 0000000000000000
[ 6401.641601] FS: 00007f2ffbab1740(0000) GS:ffff9118f7840000(0000) knlGS:0000000000000000
[ 6401.642174] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6401.642653] CR2: 0000000000000010 CR3: 00000001b402e000 CR4: 0000000000750ee0
[ 6401.643193] PKRU: 55555554
[ 6401.643548] note: python3[2673] exited with irqs disabled

-- Daniel

> thanks,
>
> greg k-h