Bug 205921

Summary: WARNING: CPU: 2 PID: 1 at kernel/trace/ftrace.c:987 ftrace_init_tracefs_toplevel
Product: Tracing/Profiling Reporter: Chris Murphy (bugzilla)
Component: FtraceAssignee: Steven Rostedt (rostedt)
Status: RESOLVED PATCH_ALREADY_AVAILABLE    
Severity: normal    
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 5.4.0 Subsystem:
Regression: Yes Bisected commit-id:
Attachments: dmesg

Description Chris Murphy 2019-12-19 21:45:06 UTC
Created attachment 286371 [details]
dmesg

Since early 5.4 RCs through 5.4.5, I'm seeing this warning which taints the kernel. Happens on every boot.

Full dmesg attached.

Also reported  here but there's no recent status update
https://lkml.org/lkml/2019/11/1/678


Dec 19 14:21:16 flap.local kernel: ------------[ cut here ]------------
Dec 19 14:21:16 flap.local kernel: Could not register function stat for cpu 0
Dec 19 14:21:16 flap.local kernel: WARNING: CPU: 2 PID: 1 at kernel/trace/ftrace.c:987 ftrace_init_tracefs_toplevel+0x12d/0x17e
Dec 19 14:21:16 flap.local kernel: Modules linked in:
Dec 19 14:21:16 flap.local kernel: CPU: 2 PID: 1 Comm: swapper/0 Not tainted 5.4.5-300.fc31.x86_64 #1
Dec 19 14:21:16 flap.local kernel: Hardware name: HP HP Spectre Notebook/81A0, BIOS F.43 04/16/2019
Dec 19 14:21:16 flap.local kernel: RIP: 0010:ftrace_init_tracefs_toplevel+0x12d/0x17e
Dec 19 14:21:16 flap.local kernel: Code: b9 0e 00 00 00 48 8d 78 20 f3 a5 4c 89 70 20 48 8d 78 20 e8 30 6d 34 fe 85 c0 74 84 89 ee 48 c7 c7 38 75 34 83 e8 ac fc 24 fe <0f> 0b 5b 4c 89 f7 5d 41 5c 41 5d 41 5e e9 0c 16 44 fe 31 c9 49 c7
Dec 19 14:21:16 flap.local kernel: RSP: 0000:ffffb3314007bdf0 EFLAGS: 00010286
Dec 19 14:21:16 flap.local kernel: RAX: 0000000000000000 RBX: ffff97e4f6a00000 RCX: 000000000000029d
Dec 19 14:21:16 flap.local kernel: RDX: 0000000000000001 RSI: 0000000000000092 RDI: 0000000000000247
Dec 19 14:21:16 flap.local kernel: RBP: 0000000000000000 R08: 000000000000029d R09: 0000000000000003
Dec 19 14:21:16 flap.local kernel: R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
Dec 19 14:21:16 flap.local kernel: R13: 000000000001c980 R14: ffff97e4f5296380 R15: 0000000000000000
Dec 19 14:21:16 flap.local kernel: FS:  0000000000000000(0000) GS:ffff97e4f6b00000(0000) knlGS:0000000000000000
Dec 19 14:21:16 flap.local kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Dec 19 14:21:16 flap.local kernel: CR2: 0000000000000000 CR3: 000000028f60a001 CR4: 00000000003606e0
Dec 19 14:21:16 flap.local kernel: Call Trace:
Dec 19 14:21:16 flap.local kernel:  tracer_init_tracefs+0x8c/0x1e7
Dec 19 14:21:16 flap.local kernel:  ? register_tracer+0x1bc/0x1bc
Dec 19 14:21:16 flap.local kernel:  do_one_initcall+0x46/0x1f4
Dec 19 14:21:16 flap.local kernel:  kernel_init_freeable+0x1a7/0x24e
Dec 19 14:21:16 flap.local kernel:  ? rest_init+0xaa/0xaa
Dec 19 14:21:16 flap.local kernel:  kernel_init+0xa/0x106
Dec 19 14:21:16 flap.local kernel:  ret_from_fork+0x35/0x40
Dec 19 14:21:16 flap.local kernel: ---[ end trace 8653078ac364f7e6 ]---
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'tracing_thresh' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'README' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'saved_cmdlines' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'saved_cmdlines_size' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'saved_tgids' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'eval_map' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'dyn_ftrace_total_info' entry
Dec 19 14:21:16 flap.local kernel: Lockdown: swapper/0: use of tracefs is restricted; see man kernel_lockdown.7
Dec 19 14:21:16 flap.local kernel: Could not create tracefs 'funcgraph-overrun' entry
Dec 19 14:21:16 flap.local kernel: ------------[ cut here ]------------
Dec 19 14:21:16 flap.local kernel: Failed to create trace option: funcgraph-overrun
Dec 19 14:21:16 flap.local kernel: WARNING: CPU: 2 PID: 1 at kernel/trace/trace.c:8106 create_trace_option_files+0x1ef/0x220
Dec 19 14:21:16 flap.local kernel: Modules linked in:
Dec 19 14:21:16 flap.local kernel: CPU: 2 PID: 1 Comm: swapper/0 Tainted: G        W         5.4.5-300.fc31.x86_64 #1
Dec 19 14:21:16 flap.local kernel: Hardware name: HP HP Spectre Notebook/81A0, BIOS F.43 04/16/2019
Dec 19 14:21:16 flap.local kernel: RIP: 0010:create_trace_option_files+0x1ef/0x220
Dec 19 14:21:16 flap.local kernel: Code: 48 85 c0 75 96 48 8b 43 18 eb b6 80 3d fb ed 61 01 00 75 b2 49 8b 37 48 c7 c7 a8 8b 34 83 c6 05 e8 ed 61 01 01 e8 9f c4 f0 ff <0f> 0b eb 98 bf 20 00 00 00 e9 da fe ff ff 48 8b 3c 24 48 83 c4 08
Dec 19 14:21:16 flap.local kernel: RSP: 0000:ffffb3314007bdc8 EFLAGS: 00010282
Dec 19 14:21:16 flap.local kernel: RAX: 0000000000000000 RBX: ffff97e4f4966400 RCX: 0000000000000000
Dec 19 14:21:16 flap.local kernel: RDX: 0000000000000030 RSI: ffffffff84126570 RDI: 0000000000000246
Dec 19 14:21:16 flap.local kernel: RBP: ffffffff836cfc20 R08: 000000001dc435ad R09: 0000000000000030
Dec 19 14:21:16 flap.local kernel: R10: ffffffff84126920 R11: 000000008412655e R12: ffffffff836d21c0
Dec 19 14:21:16 flap.local kernel: R13: ffffffff836d21e0 R14: 0000000000000000 R15: ffffffff836d21e0
Dec 19 14:21:16 flap.local kernel: FS:  0000000000000000(0000) GS:ffff97e4f6b00000(0000) knlGS:0000000000000000
Dec 19 14:21:16 flap.local kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Dec 19 14:21:16 flap.local kernel: CR2: 0000000000000000 CR3: 000000028f60a001 CR4: 00000000003606e0
Dec 19 14:21:16 flap.local kernel: Call Trace:
Dec 19 14:21:16 flap.local kernel:  __update_tracer_options+0x26/0x40
Dec 19 14:21:16 flap.local kernel:  tracer_init_tracefs+0x1d6/0x1e7
Dec 19 14:21:16 flap.local kernel:  ? register_tracer+0x1bc/0x1bc
Dec 19 14:21:16 flap.local kernel:  do_one_initcall+0x46/0x1f4
Dec 19 14:21:16 flap.local kernel:  kernel_init_freeable+0x1a7/0x24e
Dec 19 14:21:16 flap.local kernel:  ? rest_init+0xaa/0xaa
Dec 19 14:21:16 flap.local kernel:  kernel_init+0xa/0x106
Dec 19 14:21:16 flap.local kernel:  ret_from_fork+0x35/0x40
Dec 19 14:21:16 flap.local kernel: ---[ end trace 8653078ac364f7e7 ]---
Comment 1 Chris Murphy 2019-12-19 21:49:20 UTC
I'm not seeing this in 5.5 rc1 or rc2
Comment 2 Steven Rostedt 2019-12-19 22:00:43 UTC
Should be fixed by commit: a356646a56857c2e5ad875beec734d7145ecd49a ("tracing: Do not create directories if lockdown is in affect")
Comment 3 Chris Murphy 2019-12-19 22:15:13 UTC
It's not in 5.4.5, and I don't see that it's been sent to linux-stable@.
Comment 4 Steven Rostedt 2019-12-19 22:19:51 UTC
No, but the stable team is usually good at picking up patches with the Fixes tag in them.
Comment 5 Steven Rostedt 2020-01-10 17:17:45 UTC
The fix has now been added to the 5.4 queue.