----- On Mar 28, 2022, at 4:24 PM, Mathieu Desnoyers [email protected] wrote:
> Hi Beau, Hi Steven,
>
> I've done a review of the trace events ABI, and I have a few comments.
> Sorry for being late to the party, but I only noticed this new ABI recently.
> Hopefully we can improve this ABI before the 5.18 release.
>
Also a bit of testing shows that dyn_event_add() is called without holding the event_mutex.
Has this been tested with lockdep ?
[ 144.192299] ------------[ cut here ]------------
[ 144.194026] WARNING: CPU: 10 PID: 2689 at kernel/trace/trace_dynevent.h:82 user_event_parse_cmd+0x972/0xa00
[ 144.196850] Modules linked in:
[ 144.197836] CPU: 10 PID: 2689 Comm: example Not tainted 5.17.0+ #269
[ 144.199805] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[ 144.202303] RIP: 0010:user_event_parse_cmd+0x972/0xa00
[ 144.203899] Code: 48 00 00 00 00 e9 cf f8 ff ff 41 bf f4 ff ff ff e9 3a f7 ff ff be ff ff ff ff 48 c7 c7 08 bb f7 8a e8 b2 05 de 00 85 c0 75 02 <0f> 0b 48 83 bb 30 01 00 00 00 0f 84 54 fa ff ff e9 25 fa ff ff 48
[ 144.209398] RSP: 0018:ffffb6264b87be10 EFLAGS: 00010246
[ 144.211098] RAX: 0000000000000000 RBX: ffff9c3045cb7c00 RCX: 0000000000000001
[ 144.213314] RDX: 0000000000000000 RSI: ffffffff8aa2d11e RDI: ffffffff8aac2f16
[ 144.215577] RBP: ffff9c3045cb7d20 R08: 0000000000000001 R09: 0000000000000001
[ 144.217723] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000011
[ 144.221511] R13: ffffb6264b87bea8 R14: 000000000000000c R15: 0000000000000000
[ 144.223760] FS: 00007ff6d10e54c0(0000) GS:ffff9c3627a80000(0000) knlGS:0000000000000000
[ 144.226364] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 144.228203] CR2: 00007ff6d0b16a80 CR3: 00000006530ae004 CR4: 00000000001706e0
[ 144.230349] Call Trace:
[ 144.231307] <TASK>
[ 144.232140] ? _copy_from_user+0x68/0xa0
[ 144.233534] user_events_ioctl+0xfe/0x4d0
[ 144.234980] __x64_sys_ioctl+0x8e/0xd0
[ 144.236268] ? lockdep_hardirqs_on+0x7d/0x100
[ 144.237771] do_syscall_64+0x3a/0x80
[ 144.239036] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 144.240696] RIP: 0033:0x7ff6d0b16217
[ 144.241938] Code: b3 66 90 48 8b 05 71 4c 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 41 4c 2d 00 f7 d8 64 89 01 48
[ 144.247797] RSP: 002b:00007ffce19eb3b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 144.252578] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007ff6d0b16217
[ 144.254897] RDX: 00007ffce19eb3e0 RSI: 00000000c0082a00 RDI: 0000000000000003
[ 144.257162] RBP: 00007ffce19eb400 R08: 0000000000000003 R09: 0000000000000000
[ 144.259487] R10: 0000000000000000 R11: 0000000000000246 R12: 000056095fe00820
[ 144.261817] R13: 00007ffce19eb550 R14: 0000000000000000 R15: 0000000000000000
[ 144.264135] </TASK>
[ 144.264980] irq event stamp: 4515
[ 144.266162] hardirqs last enabled at (4523): [<ffffffff8916ab2e>] __up_console_sem+0x5e/0x70
[ 144.268987] hardirqs last disabled at (4532): [<ffffffff8916ab13>] __up_console_sem+0x43/0x70
[ 144.271739] softirqs last enabled at (4390): [<ffffffff8a400361>] __do_softirq+0x361/0x4a8
[ 144.274480] softirqs last disabled at (4385): [<ffffffff890e7554>] irq_exit_rcu+0x104/0x120
[ 144.277220] ---[ end trace 0000000000000000 ]---
--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
> ----- On Mar 28, 2022, at 4:24 PM, Mathieu Desnoyers [email protected] wrote:
>
> > Hi Beau, Hi Steven,
> >
> > I've done a review of the trace events ABI, and I have a few comments.
> > Sorry for being late to the party, but I only noticed this new ABI recently.
> > Hopefully we can improve this ABI before the 5.18 release.
> >
>
> Also a bit of testing shows that dyn_event_add() is called without holding the event_mutex.
> Has this been tested with lockdep ?
Sorry, looks like I've been running with LOCKDEP_SUPPORT without it on :(
I now have both CONFIG_LOCKDEP and CONFIG_LOCK_DEBUGGING_SUPPORT.
You are right about this, thanks! I've sent a patch.
Link: https://lore.kernel.org/all/[email protected]/
Thanks,
-Beau