On Sat, May 26, 2018 at 8:36 AM, Dmitry Vyukov <dvyu...@google.com> wrote: > On Thu, May 24, 2018 at 4:14 AM, Sergey Senozhatsky > <sergey.senozhatsky.w...@gmail.com> wrote: >>> First, we should ask what we expect from this feature. >> >> Yeah. Can't really comment on this, it's up to Tetsuo and Dmitry to >> decide. So far I've seen slightly different requirements/expectations. > > The root problem is that it's not possible to make sense out of kernel > output if message takes more than 1 line (or output non-atomically > with several printk's) because of intermixed output from several > tasks/interrupts/etc. For example, it's not generally possible to > recover crash stack trace, because one gets random mix of frames. > Humans usually, but not always, can restore most of the sense. So the > goal is to make this ought-to-be-simple task actually simple and not > requiring human intelligence and time each time. > > Prefixing each line with task/cpu/interrupt context should do the > trick as it will be possible to split kernel output into multiple > independent streams and analyze them independently. > > In our context (syzbot testing) we can enable an additional config, > and adopt parser to understand additional line prefix. But I don't > know how prefixing lines fits into a larger picture. Does it make > sense to thought out a potential extension story for this format? E.g. > user specifies set of extension records that are dumped before each > line, and then can unambiguously parse them? I guess some > consoles/interfaces will never be extended to provide access to the > extension records, so it can make sense to make them accessible in > text format too (optionally).
up We continue to get mess like this, each instance of which needs to be checked by human. BUG: unable to handle kernel NULL pointer dereference at 0000000000000000 sysfs: cannot create duplicate filename '/class/ieee80211/!' PGD 1cae7e067 P4D 1cae7e067 PUD 1b4da6067 PMD 0 Oops: 0010 [#1] SMP KASAN CPU: 1 PID: 1728 Comm: syz-executor4 Not tainted 4.17.0+ #84 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 CPU: 0 PID: 1738 Comm: syz-executor7 Not tainted 4.17.0+ #84 RIP: 0010: (null) Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Code: Call Trace: Bad RIP value. __dump_stack lib/dump_stack.c:77 [inline] dump_stack+0x1b9/0x294 lib/dump_stack.c:113 RSP: 0018:ffff88018cd3f590 EFLAGS: 00010246 RAX: 0000000000000000 RBX: ffff880192f05800 RCX: 1ffffffff10eeea9 sysfs_warn_dup.cold.3+0x1c/0x2b fs/sysfs/dir.c:30 RDX: ffff88018cd3fab0 RSI: ffff8801c927a480 RDI: ffff88018c77c040 sysfs_do_create_link_sd.isra.2+0x116/0x130 fs/sysfs/symlink.c:50 RBP: ffff88018cd3f700 R08: 0000000000000001 R09: 0000000000000000 sysfs_do_create_link fs/sysfs/symlink.c:79 [inline] sysfs_create_link+0x65/0xc0 fs/sysfs/symlink.c:91 R10: 0000000000000000 R11: 0000000000000000 R12: 1ffff100319a7eb7 R13: ffff88018cd3fab0 R14: ffff880192f05812 R15: ffff880192f05c58 device_add_class_symlinks drivers/base/core.c:1632 [inline] device_add+0x5c9/0x16f0 drivers/base/core.c:1834 FS: 00007f4a8e71f700(0000) GS:ffff8801daf00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: ffffffffffffffd6 CR3: 0000000191e1b000 CR4: 00000000001406e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 wiphy_register+0x182e/0x24e0 net/wireless/core.c:813 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: ieee80211_register_hw+0x13cd/0x35d0 net/mac80211/main.c:1050 sock_poll+0x1d1/0x710 net/socket.c:1168 mac80211_hwsim_new_radio+0x1da2/0x33b0 drivers/net/wireless/mac80211_hwsim.c:2772 vfs_poll+0x77/0x2a0 fs/select.c:40 do_pollfd fs/select.c:848 [inline] do_poll fs/select.c:896 [inline] do_sys_poll+0x6fd/0x1100 fs/select.c:990 hwsim_new_radio_nl+0x7b8/0xa60 drivers/net/wireless/mac80211_hwsim.c:3247 genl_family_rcv_msg+0x889/0x1120 net/netlink/genetlink.c:599 genl_rcv_msg+0xc6/0x170 net/netlink/genetlink.c:624 netlink_rcv_skb+0x172/0x440 net/netlink/af_netlink.c:2448 __do_sys_poll fs/select.c:1048 [inline] __se_sys_poll fs/select.c:1036 [inline] __x64_sys_poll+0x189/0x510 fs/select.c:1036 genl_rcv+0x28/0x40 net/netlink/genetlink.c:635 netlink_unicast_kernel net/netlink/af_netlink.c:1310 [inline] netlink_unicast+0x58b/0x740 net/netlink/af_netlink.c:1336 do_syscall_64+0x1b1/0x800 arch/x86/entry/common.c:290 netlink_sendmsg+0x9f0/0xfa0 net/netlink/af_netlink.c:1901 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x455b29 sock_sendmsg_nosec net/socket.c:645 [inline] sock_sendmsg+0xd5/0x120 net/socket.c:655 Code: ___sys_sendmsg+0x805/0x940 net/socket.c:2161 1d ba fb ff c3 66 2e 0f 1f __sys_sendmsg+0x115/0x270 net/socket.c:2199 84 00 00 00 __do_sys_sendmsg net/socket.c:2208 [inline] __se_sys_sendmsg net/socket.c:2206 [inline] __x64_sys_sendmsg+0x78/0xb0 net/socket.c:2206 00 do_syscall_64+0x1b1/0x800 arch/x86/entry/common.c:290 00 66 90 48 89 f8 48 89 entry_SYSCALL_64_after_hwframe+0x49/0xbe f7 RIP: 0033:0x455b29 48 Code: 89 1d d6 ba fb 48 ff 89 c3 ca 66 4d 2e 89 0f c2 1f 4d 84 89 00 c8 00 4c 00 8b 00 4c 00 24 08 66 0f 90 05 <48> 48 3d 89 01 f8 f0 48 ff ff 89 0f 83 f7 eb 48 b9 fb 89 ff d6 c3 48 89 66 ca 4d 2e 89 0f c2 1f 4d 84 89 00 c8 00 4c 00 8b 00 4c RSP: 002b:00007f4a8e71ec68 EFLAGS: 00000246 24 ORIG_RAX: 0000000000000007 08 RAX: ffffffffffffffda RBX: 00007f4a8e71f6d4 RCX: 0000000000455b29 0f RDX: 0000000000000004 RSI: 0000000000000005 RDI: 0000000020000000 05 RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000 <48> 3d R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff 01 R13: 00000000004c06c7 R14: 00000000004d0030 R15: 0000000000000000 f0 Modules linked in: ff Dumping ftrace buffer: ff (ftrace buffer empty) 0f CR2: 0000000000000000 83 ---[ end trace 69744e61e26ed6a4 ]--- eb b9 fb ff c3 66 2e RIP: 0010: (null) 0f 1f 84 00 00 00 Code: 00 RSP: 002b:00007f4e4fdedc68 EFLAGS: 00000246 ORIG_RAX: 000000000000002e Bad RIP value. RAX: ffffffffffffffda RBX: 00007f4e4fdee6d4 RCX: 0000000000455b29 RDX: 0000000000000000 RSI: 0000000020000080 RDI: 0000000000000014 RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000 RSP: 0018:ffff88018cd3f590 EFLAGS: 00010246 R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff R13: 00000000004c0ee7 R14: 00000000004d0d80 R15: 0000000000000000 RAX: 0000000000000000 RBX: ffff880192f05800 RCX: 1ffffffff10eeea9 RDX: ffff88018cd3fab0 RSI: ffff8801c927a480 RDI: ffff88018c77c040 RBP: ffff88018cd3f700 R08: 0000000000000001 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: 1ffff100319a7eb7 R13: ffff88018cd3fab0 R14: ffff880192f05812 R15: ffff880192f05c58 FS: 00007f4a8e71f700(0000) GS:ffff8801daf00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 netlink: 8 bytes leftover after parsing attributes in process `syz-executor2'. CR2: ffffffffffffffd6 CR3: 0000000191e1b000 CR4: 00000000001406e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400