check that console contents are initialized

[dvyukov]

Example report below. We only detect the uninit when we read out console output from /dev/kmsg. If we don't read it out, we don't detect it. Even if we do, we detect it too late and attribute all such info leaks to do_syslog. We should detect them right in printk and attribute to the function that prints uninits.

BUG: KMSAN: kernel-infoleak in _copy_to_user+0x16b/0x1f0 lib/usercopy.c:32
CPU: 1 PID: 10710 Comm: rsyslogd Not tainted 5.0.0+ #16
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x173/0x1d0 lib/dump_stack.c:113
 kmsan_report+0x131/0x2a0 mm/kmsan/kmsan.c:636
 kmsan_internal_check_memory+0x5c6/0xbb0 mm/kmsan/kmsan.c:701
 kmsan_copy_to_user+0xab/0xc0 mm/kmsan/kmsan_hooks.c:485
 _copy_to_user+0x16b/0x1f0 lib/usercopy.c:32
 copy_to_user include/linux/uaccess.h:174 [inline]
 syslog_print kernel/printk/printk.c:1362 [inline]
 do_syslog+0x3c22/0x3ef0 kernel/printk/printk.c:1487
 kmsg_read+0x142/0x1a0 fs/proc/kmsg.c:40
 proc_reg_read+0x2a2/0x3d0 fs/proc/inode.c:229
 __vfs_read+0x1e5/0xbf0 fs/read_write.c:416
 vfs_read+0x359/0x6f0 fs/read_write.c:452
 ksys_read fs/read_write.c:578 [inline]
 __do_sys_read fs/read_write.c:588 [inline]
 __se_sys_read+0x17a/0x370 fs/read_write.c:586
 __x64_sys_read+0x4a/0x70 fs/read_write.c:586
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:291
 entry_SYSCALL_64_after_hwframe+0x63/0xe7
RIP: 0033:0x7fd84c4b71fd
Code: d1 20 00 00 75 10 b8 00 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 5e fa ff ff 48 89 04 24 b8 00 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 a7 fa ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007fd849a56e30 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000000000160cce0 RCX: 00007fd84c4b71fd
RDX: 0000000000000fff RSI: 00007fd84b28b5a0 RDI: 0000000000000004
RBP: 0000000000000000 R08: 00000000015f8260 R09: 0000000004000001
R10: 0000000000000001 R11: 0000000000000293 R12: 000000000065e420
R13: 00007fd849a579c0 R14: 00007fd84cafc040 R15: 0000000000000003

Uninit was stored to memory at:
 kmsan_save_stack_with_flags mm/kmsan/kmsan.c:205 [inline]
 kmsan_save_stack mm/kmsan/kmsan.c:220 [inline]
 kmsan_internal_chain_origin+0x134/0x230 mm/kmsan/kmsan.c:426
 kmsan_memcpy_memmove_metadata+0xb5b/0xfe0 mm/kmsan/kmsan.c:304
 kmsan_memcpy_metadata+0xb/0x10 mm/kmsan/kmsan.c:324
 __msan_memcpy+0x58/0x70 mm/kmsan/kmsan_instr.c:139
 msg_print_text+0x5bc/0x770 kernel/printk/printk.c:1294
 syslog_print kernel/printk/printk.c:1343 [inline]
 do_syslog+0x37fc/0x3ef0 kernel/printk/printk.c:1487
 kmsg_read+0x142/0x1a0 fs/proc/kmsg.c:40
 proc_reg_read+0x2a2/0x3d0 fs/proc/inode.c:229
 __vfs_read+0x1e5/0xbf0 fs/read_write.c:416
 vfs_read+0x359/0x6f0 fs/read_write.c:452
 ksys_read fs/read_write.c:578 [inline]
 __do_sys_read fs/read_write.c:588 [inline]
 __se_sys_read+0x17a/0x370 fs/read_write.c:586
 __x64_sys_read+0x4a/0x70 fs/read_write.c:586
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:291
 entry_SYSCALL_64_after_hwframe+0x63/0xe7

Uninit was stored to memory at:
 kmsan_save_stack_with_flags mm/kmsan/kmsan.c:205 [inline]
 kmsan_save_stack mm/kmsan/kmsan.c:220 [inline]
 kmsan_internal_chain_origin+0x134/0x230 mm/kmsan/kmsan.c:426
 kmsan_memcpy_memmove_metadata+0xb5b/0xfe0 mm/kmsan/kmsan.c:304
 kmsan_memcpy_metadata+0xb/0x10 mm/kmsan/kmsan.c:324
 __msan_memcpy+0x58/0x70 mm/kmsan/kmsan_instr.c:139
 log_store+0xdea/0x1370 kernel/printk/printk.c:625
 log_output kernel/printk/printk.c:1848 [inline]
 vprintk_store+0x9d2/0xed0 kernel/printk/printk.c:1901
 vprintk_emit+0x2c6/0x840 kernel/printk/printk.c:1925
 vprintk_default+0x90/0xa0 kernel/printk/printk.c:1970
 vprintk_func+0x635/0x820 kernel/printk/printk_safe.c:398
 printk+0x186/0x1d0 kernel/printk/printk.c:2003
 tipc_enable_bearer net/tipc/bearer.c:339 [inline]
 __tipc_nl_bearer_enable+0x106f/0x1d50 net/tipc/bearer.c:899
 tipc_nl_bearer_enable+0x6c/0xb0 net/tipc/bearer.c:907
 genl_family_rcv_msg net/netlink/genetlink.c:601 [inline]
 genl_rcv_msg+0x185f/0x1a60 net/netlink/genetlink.c:626
 netlink_rcv_skb+0x431/0x620 net/netlink/af_netlink.c:2477
 genl_rcv+0x63/0x80 net/netlink/genetlink.c:637
 netlink_unicast_kernel net/netlink/af_netlink.c:1310 [inline]
 netlink_unicast+0xf3e/0x1020 net/netlink/af_netlink.c:1336
 netlink_sendmsg+0x127f/0x1300 net/netlink/af_netlink.c:1917
 sock_sendmsg_nosec net/socket.c:622 [inline]
 sock_sendmsg net/socket.c:632 [inline]
 ___sys_sendmsg+0xdb9/0x11b0 net/socket.c:2115
 __sys_sendmsg net/socket.c:2153 [inline]
 __do_sys_sendmsg net/socket.c:2162 [inline]
 __se_sys_sendmsg+0x305/0x460 net/socket.c:2160
 __x64_sys_sendmsg+0x4a/0x70 net/socket.c:2160
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:291
 entry_SYSCALL_64_after_hwframe+0x63/0xe7

Uninit was stored to memory at:
 kmsan_save_stack_with_flags mm/kmsan/kmsan.c:205 [inline]
 kmsan_save_stack mm/kmsan/kmsan.c:220 [inline]
 kmsan_internal_chain_origin+0x134/0x230 mm/kmsan/kmsan.c:426
 __msan_chain_origin+0x70/0xe0 mm/kmsan/kmsan_instr.c:200
 string+0x276/0x340 lib/vsprintf.c:609
 vsnprintf+0x1181/0x30e0 lib/vsprintf.c:2396
 vscnprintf+0xc2/0x180 lib/vsprintf.c:2499
 vprintk_store+0xef/0xed0 kernel/printk/printk.c:1865
 vprintk_emit+0x2c6/0x840 kernel/printk/printk.c:1925
 vprintk_default+0x90/0xa0 kernel/printk/printk.c:1970
 vprintk_func+0x635/0x820 kernel/printk/printk_safe.c:398
 printk+0x186/0x1d0 kernel/printk/printk.c:2003
 tipc_enable_bearer net/tipc/bearer.c:339 [inline]
 __tipc_nl_bearer_enable+0x106f/0x1d50 net/tipc/bearer.c:899
 tipc_nl_bearer_enable+0x6c/0xb0 net/tipc/bearer.c:907
 genl_family_rcv_msg net/netlink/genetlink.c:601 [inline]
 genl_rcv_msg+0x185f/0x1a60 net/netlink/genetlink.c:626
 netlink_rcv_skb+0x431/0x620 net/netlink/af_netlink.c:2477
 genl_rcv+0x63/0x80 net/netlink/genetlink.c:637
 netlink_unicast_kernel net/netlink/af_netlink.c:1310 [inline]
 netlink_unicast+0xf3e/0x1020 net/netlink/af_netlink.c:1336
 netlink_sendmsg+0x127f/0x1300 net/netlink/af_netlink.c:1917
 sock_sendmsg_nosec net/socket.c:622 [inline]
 sock_sendmsg net/socket.c:632 [inline]
 ___sys_sendmsg+0xdb9/0x11b0 net/socket.c:2115
 __sys_sendmsg net/socket.c:2153 [inline]
 __do_sys_sendmsg net/socket.c:2162 [inline]
 __se_sys_sendmsg+0x305/0x460 net/socket.c:2160
 __x64_sys_sendmsg+0x4a/0x70 net/socket.c:2160
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:291
 entry_SYSCALL_64_after_hwframe+0x63/0xe7

Uninit was created at:
 kmsan_save_stack_with_flags mm/kmsan/kmsan.c:205 [inline]
 kmsan_internal_poison_shadow+0x92/0x150 mm/kmsan/kmsan.c:159
 kmsan_kmalloc+0xa6/0x130 mm/kmsan/kmsan_hooks.c:173
 kmsan_slab_alloc+0xe/0x10 mm/kmsan/kmsan_hooks.c:182
 slab_post_alloc_hook mm/slab.h:445 [inline]
 slab_alloc_node mm/slub.c:2773 [inline]
 __kmalloc_node_track_caller+0xe9e/0xff0 mm/slub.c:4398
 __kmalloc_reserve net/core/skbuff.c:140 [inline]
 __alloc_skb+0x309/0xa20 net/core/skbuff.c:208
 alloc_skb include/linux/skbuff.h:1012 [inline]
 netlink_alloc_large_skb net/netlink/af_netlink.c:1182 [inline]
 netlink_sendmsg+0xb82/0x1300 net/netlink/af_netlink.c:1892
 sock_sendmsg_nosec net/socket.c:622 [inline]
 sock_sendmsg net/socket.c:632 [inline]
 ___sys_sendmsg+0xdb9/0x11b0 net/socket.c:2115
 __sys_sendmsg net/socket.c:2153 [inline]
 __do_sys_sendmsg net/socket.c:2162 [inline]
 __se_sys_sendmsg+0x305/0x460 net/socket.c:2160
 __x64_sys_sendmsg+0x4a/0x70 net/socket.c:2160
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:291
 entry_SYSCALL_64_after_hwframe+0x63/0xe7

Bytes 50-51 of 87 are uninitialized
Memory access of size 87 starts at ffff888043bfac00
Data copied to user address 00007fd84b28b617

[ramosian-glider]

Not sure about this particular error report, but the currently reproducible one:

==================================================================
BUG: KMSAN: kernel-infoleak in _copy_to_user+0x16b/0x1f0 lib/usercopy.c:32
CPU: 1 PID: 12435 Comm: rsyslogd Not tainted 5.2.0+ #15
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x191/0x1f0 lib/dump_stack.c:113
 kmsan_report+0x162/0x2d0 mm/kmsan/kmsan_report.c:109
 kmsan_internal_check_memory+0x544/0xa80 mm/kmsan/kmsan.c:522
 kmsan_copy_to_user+0xa9/0xb0 mm/kmsan/kmsan_hooks.c:493
 _copy_to_user+0x16b/0x1f0 lib/usercopy.c:32
 copy_to_user include/linux/uaccess.h:174 [inline]
 syslog_print kernel/printk/printk.c:1406 [inline]
 do_syslog+0x2e62/0x3160 kernel/printk/printk.c:1531
 kmsg_read+0x142/0x1a0 fs/proc/kmsg.c:40
 proc_reg_read+0x25f/0x360 fs/proc/inode.c:221
 __vfs_read+0x1a9/0xc90 fs/read_write.c:425
 vfs_read+0x359/0x6f0 fs/read_write.c:461
 ksys_read+0x265/0x430 fs/read_write.c:587
 __do_sys_read fs/read_write.c:597 [inline]
 __se_sys_read+0x92/0xb0 fs/read_write.c:595
 __x64_sys_read+0x4a/0x70 fs/read_write.c:595
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:302
 entry_SYSCALL_64_after_hwframe+0x63/0xe7
RIP: 0033:0x7feb18b301fd
Code: d1 20 00 00 75 10 b8 00 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 5e fa ff ff 48 89 04 24 b8 00 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 a7 fa ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007feb160cfe30 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 0000000000c9b4b0 RCX: 00007feb18b301fd
RDX: 0000000000000fff RSI: 00007feb179045a0 RDI: 0000000000000004
RBP: 0000000000000000 R08: 0000000000c86260 R09: 0000000004000001
R10: 0000000000000001 R11: 0000000000000293 R12: 000000000065e420
R13: 00007feb160d09c0 R14: 00007feb19175040 R15: 0000000000000003

Uninit was created at:
 kmsan_save_stack_with_flags mm/kmsan/kmsan.c:187 [inline]
 kmsan_internal_poison_shadow+0x53/0xa0 mm/kmsan/kmsan.c:146
 kmsan_slab_alloc+0xaa/0x120 mm/kmsan/kmsan_hooks.c:175
 slab_alloc_node mm/slub.c:2771 [inline]
 slab_alloc mm/slub.c:2780 [inline]
 kmem_cache_alloc_trace+0x873/0xa50 mm/slub.c:2797
 kmalloc include/linux/slab.h:547 [inline]
 syslog_print kernel/printk/printk.c:1358 [inline]
 do_syslog+0x263b/0x3160 kernel/printk/printk.c:1531
 kmsg_read+0x142/0x1a0 fs/proc/kmsg.c:40
 proc_reg_read+0x25f/0x360 fs/proc/inode.c:221
 __vfs_read+0x1a9/0xc90 fs/read_write.c:425
 vfs_read+0x359/0x6f0 fs/read_write.c:461
 ksys_read+0x265/0x430 fs/read_write.c:587
 __do_sys_read fs/read_write.c:597 [inline]
 __se_sys_read+0x92/0xb0 fs/read_write.c:595
 __x64_sys_read+0x4a/0x70 fs/read_write.c:595
 do_syscall_64+0xbc/0xf0 arch/x86/entry/common.c:302
 entry_SYSCALL_64_after_hwframe+0x63/0xe7

Byte 116 of 118 is uninitialized
Memory access of size 118 starts at ffff88811b37ec00
Data copied to user address 00007feb179045a0
==================================================================

seems to be an actual bug in syslog_print() that goes away if I change it to allocate with kzalloc()`.
Not sure yet what's causing it.

Checking uninit printk arguments is doable, yet requires some changes to printk implementation.
The problem is that printk() iterates over the arguments under the console lock that disables error reporting.

[ramosian-glider]

There's been a bunch of printk changes in the past years, I think we are better at reporting bugs in printk() now