Re: [tracepoint] 01edfaf177: WARNING:at_kernel/static_call.c:#__static_call_update

[Peter Zijlstra]

On Wed, May 13, 2020 at 04:48:11PM +0800, kernel test robot wrote:

> commit: 01edfaf177311fba9941254793431d2044b00fd7 ("[PATCH v4 12/18] tracepoint: Optimize using static_call()")
> url: https://github.com/0day-ci/linux/commits/Peter-Zijlstra/Add-static_call/20200502-045208

*groan*, so I would really rather you grab patches from by git tree than
suck random crap from lkml like this :/

Anyway, I _suspect_ this is fixed in a later patch that initializes
static_call earlier, but I can't tell for sure, because I really
don't know what to do to reproduce this.

> [    1.990628] WARNING: CPU: 0 PID: 0 at kernel/static_call.c:113 __static_call_update+0x83/0x29c
> [    1.990660] Modules linked in:
> [    1.990703] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.7.0-rc3-next-20200501-00012-g01edfaf177311f #1
> [    1.990742] RIP: 0010:__static_call_update+0x83/0x29c
> [    1.990781] Code: 4c 89 f2 48 ff 05 d1 9d 83 06 e8 8e 09 d2 ff 48 ff 05 d5 9d 83 06 80 3d 8e a2 83 06 00 0f 85 f3 01 00 00 48 ff 05 c9 9d 83 06 <0f> 0b 48 ff 05 c8 9d 83 06 48 ff 05 c9 9d 83 06 e9 b0 01 00 00 48
> [    1.990814] RSP: 0000:ffffffff83c07cf8 EFLAGS: 00010002
> [    1.990850] RAX: 0000000000000000 RBX: ffffffff86682620 RCX: 0000000000000000
> [    1.990884] RDX: fffffbfff0780f87 RSI: ffffffff83c918c0 RDI: fffffbfff0780f93
> [    1.990916] RBP: ffffffff812943ec R08: fffffbfff07e3551 R09: fffffbfff07e3551
> [    1.990950] R10: ffffffff83f1aa87 R11: 0000000000000001 R12: ffffffff83f6f0c0
> [    1.990982] R13: 00000000ffffffff R14: ffffffff812943ec R15: ffffffff812943ec
> [    1.991017] FS:  0000000000000000(0000) GS:ffff8881e8000000(0000) knlGS:0000000000000000
> [    1.991049] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [    1.991081] CR2: ffff88823ffff000 CR3: 0000000003c78000 CR4: 00000000000006b0
> [    1.991119] Call Trace:
> [    1.991164]  ? __SCT__tp_func_sched_waking+0x8/0x8
> [    1.991202]  ? allocate_probes+0x2d/0x4d
> [    1.991250]  ? probe_sched_switch+0x4f/0x4f
> [    1.991286]  ? __SCT__tp_func_sched_waking+0x8/0x8
> [    1.991331]  ? probe_sched_switch+0x4f/0x4f
> [    1.991366]  tracepoint_update_call+0x6d/0x79
> [    1.991416]  tracepoint_probe_register_prio+0x337/0x47f
> [    1.991499]  tracepoint_probe_register+0x16/0x1e
> [    1.991538]  tracing_start_sched_switch+0xc3/0x1ba
> [    1.991627]  tracing_start_cmdline_record+0x11/0x19
> [    1.991664]  trace_printk_start_comm+0x1c/0x24
> [    1.991725]  trace_event_init+0x1b8/0x20a
> [    1.991775]  trace_init+0xc/0x14
> [    1.991809]  start_kernel+0x8ed/0xe78
> [    1.991862]  ? thread_stack_cache_init+0xd/0xd
> [    1.991905]  ? __early_make_pgtable+0x1b9/0x204
> [    1.991963]  ? early_make_pgtable+0x27/0x2f
> [    1.992000]  ? early_idt_handler_common+0x35/0x4c
> [    1.992131]  x86_64_start_reservations+0x42/0x4a
> [    1.992170]  x86_64_start_kernel+0xe1/0xea
> [    1.992216]  secondary_startup_64+0xa4/0xb0
> [    1.992336] irq event stamp: 0
> [    1.992371] hardirqs last  enabled at (0): [<0000000000000000>] 0x0
> [    1.992403] hardirqs last disabled at (0): [<0000000000000000>] 0x0
> [    1.992437] softirqs last  enabled at (0): [<0000000000000000>] 0x0
> [    1.992469] softirqs last disabled at (0): [<0000000000000000>] 0x0
> [    1.992562] ---[ end trace 15ea566c311b9aea ]---
> 
> 
> To reproduce:
> 
>         # build kernel
> 	cd linux
> 	cp config-5.7.0-rc3-next-20200501-00012-g01edfaf177311f .config
> 	make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
> 
>         git clone https://github.com/intel/lkp-tests.git
>         cd lkp-tests
>         bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email

Because ^ is just not going to happen. And from the provided information
I cannot decipher what it takes to trigger this.

Also, your dmesg had the trace_printk() splat in, and that is certainly
not from these patches.