trace_printk() is used in kernel

[kcome]

When i was debugging an issue, in the dmesg I found the notice shown above in the output.

I'm not kernel expert but just sending the output here. Maybe some switch needs to be turned off.

Oh, I just updated manually, and the kernel version is:

$ uname -a
Linux clr 5.16.18-1137.native #1 SMP Mon Mar 28 03:03:20 PDT 2022 x86_64 GNU/Linux
$ swupd info
Distribution:      Clear Linux OS
Installed version: 36120
Version URL:       https://cdn.download.clearlinux.org/update
Content URL:       https://cdn.download.clearlinux.org/update

[mmorini]

Same here. Same kernel, apparently happens super early, before any module has the opportunity to be loaded.

[ 0.133935] printk: log_buf_len individual max cpu contribution: 4096 bytes
[ 0.133936] printk: log_buf_len total cpu_extra contributions: 126976 bytes
[ 0.133936] printk: log_buf_len min size: 131072 bytes
[ 0.134116] printk: log_buf_len: 262144 bytes
[ 0.134117] printk: early log buf free: 110800(84%)

[fenrus75]

is there anything weird else in the logs?

…

On Sun, Apr 10, 2022, 06:50 Matteo Morini ***@***.***> wrote: Same here. Same kernel, apparently happens super early, before any module has the opportunity to be loaded. — Reply to this email directly, view it on GitHub <#2615 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAJ54FKRPHPS74QLV54U4HDVELMD7ANCNFSM5SSNSMIA> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[mmorini]

By the naked eye, nothing. Days later, though, a couple

[224108.533994] bulkfree_pcp_prepare()::1642 800000000000010
[224108.691907] post_alloc_hook()::2617 BAD page private: priv=800000000000000
[224108.691913] CPU: 21 PID: 2924743 Comm: updatedb Not tainted 5.16.18-1137.native #1

appeared. I became confused by the successive Not tainted -> taint[ed] transition (no kernel modules were loaded in between)

[224108.825621] Disabling lock debugging due to kernel taint

btrfs seems somehow implied:

[224110.900211] Call Trace:
[224110.900213]  <TASK>
[224110.900217]  show_stack+0x46/0x58
[224110.900224]  dump_stack_lvl+0x38/0x51
[224110.900227]  dump_stack+0x10/0x14
[224110.900229]  post_alloc_hook.cold+0x2b/0x30
[224110.900234]  prep_new_page+0x1b/0x80
[224110.900238]  get_page_from_freelist+0x31e/0x440
[224110.900241]  __alloc_pages+0x16a/0x300
[224110.900243]  alloc_pages+0x9c/0x1c0
[224110.900245]  folio_alloc+0x16/0x80
[224110.900247]  filemap_alloc_folio+0x87/0xc0
[224110.900250]  __filemap_get_folio+0x117/0x300
[224110.900253]  ? read_extent_buffer+0x89/0xc0
[224110.900257]  pagecache_get_page+0x12/0x80
[224110.900260]  alloc_extent_buffer+0x23f/0x5c0
[224110.900262]  read_tree_block+0x1d/0xc0
[224110.900266]  read_block_for_search+0x189/0x240
[224110.900269]  btrfs_search_slot+0x3a7/0xa00
[224110.900272]  btrfs_lookup_dir_item+0x64/0x100
[224110.900274]  btrfs_lookup_dentry+0xb0/0x440
[224110.900276]  ? capable_wrt_inode_uidgid+0x5a/0x80
[224110.900280]  btrfs_lookup+0xe/0x40
[224110.900281]  __lookup_slow+0x70/0x140
[224110.900285]  walk_component+0x125/0x1c0
[224110.900287]  ? try_to_unlazy+0x3e/0x80
[224110.900289]  path_lookupat+0x69/0x1c0
[224110.900290]  filename_lookup+0xb7/0x1c0
[224110.900292]  ? __check_object_size+0x1a/0x40
[224110.900295]  ? strncpy_from_user+0x53/0x180
[224110.900297]  ? getname_flags.part.0+0x4b/0x1c0
[224110.900299]  user_path_at_empty+0x3a/0x80
[224110.900300]  vfs_statx+0x66/0x100
[224110.900302]  __do_sys_newlstat+0x2f/0x80
[224110.900304]  ? __secure_computing+0x92/0x100
[224110.900307]  ? syscall_trace_enter.constprop.0+0xb0/0x200
[224110.900311]  __x64_sys_newlstat+0x11/0x40
[224110.900312]  do_syscall_64+0x3b/0xc0
[224110.900316]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[224110.900319] RIP: 0033:0x7fc86e23343a
[224110.900321] Code: ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 f3 0f 1e fa 41 89 f8 48 89 f7 48 89 d:
[224110.900323] RSP: 002b:00007ffd092e6138 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
[224110.900325] RAX: ffffffffffffffda RBX: 0000000000000006 RCX: 00007fc86e23343a
[224110.900327] RDX: 00007ffd092e61a0 RSI: 00007ffd092e61a0 RDI: 000055cb70324959
[224110.900328] RBP: 00007ffd092e62f0 R08: 0000000000000001 R09: 000055cb703083b0
[224110.900328] R10: 000055cb702ffae0 R11: 0000000000000246 R12: 000055cb70308300
[224110.900329] R13: 0000000000000006 R14: 000055cb702ffbc0 R15: 0000000000000006
[224110.900331]  </TASK>

[mmorini]

Fixed in 36150 - 5.16.18-1138.native #1 SMP Wed Apr 6 08:55:53 PDT 2022 x86_64 GNU/Linux