Hi Namhyung,
On Wed, 2019-01-16 at 15:43 +0900, Namhyung Kim wrote:
> Hi Tom,
>
> On Tue, Jan 15, 2019 at 04:05:44PM -0600, Tom Zanussi wrote:
> > From: Tom Zanussi <tom.zanussi@xxxxxxxxxxxxxxx>
> >
> > Hi,
> >
> > This is v12 of the hist trigger snapshot and onchange additions
> > patchset.
> >
> > It addresses some comments from Namhyung regarding the 'tracing:
> > Add
> > alternative synthetic event trace action syntax' patch to remove
> > parens and change the documentation to emphasize the trace() form
> > of
> > the synthetic event generation command.
>
> I got below from the following test:
>
> # echo 'hist:key=comm:p=prio:onchange($p).snapshot()' > \
> events/sched/sched_waking/trigger
>
> # echo 1 > snapshot
>
Thanks for reporting this. If there's a snapshot trigger in effect,
attempting to take a snapshot from the command-line should really
return -EBUSY - I'll update the snapshot code to do that.
Tom
>
> Thanks,
> Namhyung
>
>
>
> [ 2217.403818] BUG: sleeping function called from invalid context at
> arch/x86/mm/fault.c:1369
> [ 2217.406394] in_atomic(): 0, irqs_disabled(): 1, pid: 65, name: sh
> [ 2217.406394] 3 locks held by sh/65:
> [ 2217.406394] #0: 000000006082fdb2 (sb_writers#5){.+.+}, at:
> vfs_write+0x109/0x130
> [ 2217.406394] #1: 000000003e4def73 (trace_types_lock){+.+.}, at:
> tracing_snapshot_write+0x93/0x170
> [ 2217.406394] #2: 0000000050fd4c4a (&mm->mmap_sem){++++}, at:
> __do_page_fault+0x19a/0x4e0
> [ 2217.406394] irq event stamp: 173368
> [ 2217.406394] hardirqs last enabled at (173367):
> [<ffffffff815369e9>] _raw_spin_unlock_irq+0x29/0x40
> [ 2217.406394] hardirqs last disabled at (173368):
> [<ffffffff811079b2>] tracing_snapshot_write+0xf2/0x170
> [ 2217.406394] softirqs last enabled at (173258):
> [<ffffffff81800288>] __do_softirq+0x288/0x47c
> [ 2217.406394] softirqs last disabled at (173253):
> [<ffffffff8105a682>] irq_exit+0x62/0xa0
> [ 2217.406394] CPU: 0 PID: 65 Comm: sh Not tainted 4.20.0-rc3+ #259
> [ 2217.406394] Call Trace:
> [ 2217.406394] dump_stack+0x67/0x90
> [ 2217.406394] ___might_sleep.cold.5+0x9f/0xb1
> [ 2217.406394] __do_page_fault+0x1b7/0x4e0
> [ 2217.406394] page_fault+0x1e/0x30
> [ 2217.406394] RIP: 0010:cond_snapshot_update+0x26/0xa0
> [ 2217.406394] Code: ff ff 66 90 55 48 89 e5 41 55 41 54 53 48 8b 87
> c8 16 00 00 48 8b 18 48 83 e4 f0 48 85 db 74 20 48 8b 43 50 49 89 f4
> 48 8b 3b <48> 8b 36 48 8b 80 e0 00 00 00 e8 1b 43 6e 00 41 89 c5 84
> c0 75 11
> [ 2217.406394] RSP: 0018:ffffc90000163dc0 EFLAGS: 00010082
> [ 2217.406394] RAX: ffff88803dc07000 RBX: ffff88803df7b720 RCX:
> ffff88800008e408
> [ 2217.406394] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
> 0000000000000078
> [ 2217.406394] RBP: ffffc90000163de0 R08: 0000000000000000 R09:
> 0000000000000001
> [ 2217.406394] R10: ffffc90000163e18 R11: 0000000000000002 R12:
> 0000000000000000
> [ 2217.406394] R13: 0000000000000000 R14: ffffc90000163f08 R15:
> 0000000000000000
> [ 2217.406394] update_max_tr+0x82/0xe0
> [ 2217.406394] tracing_snapshot_write+0x15c/0x170
> [ 2217.406394] __vfs_write+0x36/0x180
> [ 2217.406394] ? rcu_read_lock_sched_held+0x76/0x80
> [ 2217.406394] ? rcu_sync_lockdep_assert+0x2e/0x60
> [ 2217.406394] ? __sb_start_write+0x14c/0x1b0
> [ 2217.406394] ? vfs_write+0x109/0x130
> [ 2217.406394] vfs_write+0xb7/0x130
> [ 2217.406394] ksys_write+0x52/0xc0
> [ 2217.406394] do_syscall_64+0x50/0x180
> [ 2217.406394] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 2217.406394] RIP: 0033:0x7f9bc3170818
> [ 2217.406394] Code: 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00
> 00 00 f3 0f 1e fa 48 8d 05 25 6d 0d 00 8b 00 85 c0 75 17 b8 01 00 00
> 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 41 54 49
> 89 d4 55
> [ 2217.406394] RSP: 002b:00007ffdef643888 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000001
> [ 2217.406394] RAX: ffffffffffffffda RBX: 0000000000000002 RCX:
> 00007f9bc3170818
> [ 2217.406394] RDX: 0000000000000002 RSI: 00005651d6bf0db0 RDI:
> 0000000000000001
> [ 2217.406394] RBP: 00005651d6bf0db0 R08: 000000000000000a R09:
> 00007ffdef643410
> [ 2217.406394] R10: 000000000000000a R11: 0000000000000246 R12:
> 00007f9bc32435c0
> [ 2217.406394] R13: 0000000000000002 R14: 00007f9bc323e5c0 R15:
> 0000000000000002
>
> [ 2217.406394] BUG: unable to handle kernel NULL pointer dereference
> at 0000000000000000
> [ 2217.406394] PGD 0 P4D 0
> [ 2217.406394] Oops: 0000 [#1] SMP PTI
> [ 2217.406394] CPU: 0 PID: 65 Comm: sh Tainted:
> G W 4.20.0-rc3+ #259
> [ 2217.406394] RIP: 0010:cond_snapshot_update+0x26/0xa0
> [ 2217.406394] Code: ff ff 66 90 55 48 89 e5 41 55 41 54 53 48 8b 87
> c8 16 00 00 48 8b 18 48 83 e4 f0 48 85 db 74 20 48 8b 43 50 49 89 f4
> 48 8b 3b <48> 8b 36 48 8b 80 e0 00 00 00 e8 1b 43 6e 00 41 89 c5 84
> c0 75 11
> [ 2217.406394] RSP: 0018:ffffc90000163dc0 EFLAGS: 00010082
> [ 2217.406394] RAX: ffff88803dc07000 RBX: ffff88803df7b720 RCX:
> ffff88800008e408
> [ 2217.406394] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
> 0000000000000078
> [ 2217.406394] RBP: ffffc90000163de0 R08: 0000000000000000 R09:
> 0000000000000001
> [ 2217.406394] R10: ffffc90000163e18 R11: 0000000000000002 R12:
> 0000000000000000
> [ 2217.406394] R13: 0000000000000000 R14: ffffc90000163f08 R15:
> 0000000000000000
> [ 2217.406394] FS: 00007f9bc3013b80(0000) GS:ffff88803e400000(0000)
> knlGS:0000000000000000
> [ 2217.406394] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 2217.406394] CR2: 0000000000000000 CR3: 000000003d138001 CR4:
> 0000000000060eb0
> [ 2217.406394] Call Trace:
> [ 2217.406394] update_max_tr+0x82/0xe0
> [ 2217.406394] tracing_snapshot_write+0x15c/0x170
> [ 2217.406394] __vfs_write+0x36/0x180
> [ 2217.406394] ? rcu_read_lock_sched_held+0x76/0x80
> [ 2217.406394] ? rcu_sync_lockdep_assert+0x2e/0x60
> [ 2217.406394] ? __sb_start_write+0x14c/0x1b0
> [ 2217.406394] ? vfs_write+0x109/0x130
> [ 2217.406394] vfs_write+0xb7/0x130
> [ 2217.406394] ksys_write+0x52/0xc0
> [ 2217.406394] do_syscall_64+0x50/0x180
> [ 2217.406394] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 2217.406394] RIP: 0033:0x7f9bc3170818
> [ 2217.406394] Code: 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00
> 00 00 f3 0f 1e fa 48 8d 05 25 6d 0d 00 8b 00 85 c0 75 17 b8 01 00 00
> 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 41 54 49
> 89 d4 55
> [ 2217.406394] RSP: 002b:00007ffdef643888 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000001
> [ 2217.406394] RAX: ffffffffffffffda RBX: 0000000000000002 RCX:
> 00007f9bc3170818
> [ 2217.406394] RDX: 0000000000000002 RSI: 00005651d6bf0db0 RDI:
> 0000000000000001
> [ 2217.406394] RBP: 00005651d6bf0db0 R08: 000000000000000a R09:
> 00007ffdef643410
> [ 2217.406394] R10: 000000000000000a R11: 0000000000000246 R12:
> 00007f9bc32435c0
> [ 2217.406394] R13: 0000000000000002 R14: 00007f9bc323e5c0 R15:
> 0000000000000002
> [ 2217.406394] Modules linked in:
> [ 2217.406394] CR2: 0000000000000000
> [ 2217.406394] ---[ end trace 832915071760c624 ]---
> [ 2217.406394] RIP: 0010:cond_snapshot_update+0x26/0xa0
> [ 2217.406394] Code: ff ff 66 90 55 48 89 e5 41 55 41 54 53 48 8b 87
> c8 16 00 00 48 8b 18 48 83 e4 f0 48 85 db 74 20 48 8b 43 50 49 89 f4
> 48 8b 3b <48> 8b 36 48 8b 80 e0 00 00 00 e8 1b 43 6e 00 41 89 c5 84
> c0 75 11
> [ 2217.406394] RSP: 0018:ffffc90000163dc0 EFLAGS: 00010082
> [ 2217.406394] RAX: ffff88803dc07000 RBX: ffff88803df7b720 RCX:
> ffff88800008e408
> [ 2217.406394] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
> 0000000000000078
> [ 2217.406394] RBP: ffffc90000163de0 R08: 0000000000000000 R09:
> 0000000000000001
> [ 2217.406394] R10: ffffc90000163e18 R11: 0000000000000002 R12:
> 0000000000000000
> [ 2217.406394] R13: 0000000000000000 R14: ffffc90000163f08 R15:
> 0000000000000000
> [ 2217.406394] FS: 00007f9bc3013b80(0000) GS:ffff88803e400000(0000)
> knlGS:0000000000000000
> [ 2217.406394] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 2217.406394] CR2: 0000000000000000 CR3: 000000003d138001 CR4:
> 0000000000060eb0
