Fix: consumerd: unbalanced subbuffer 'get' when checking operation availability
authorJérémie Galarneau <jeremie.galarneau@efficios.com>
Thu, 29 Apr 2021 20:17:45 +0000 (16:17 -0400)
committerJérémie Galarneau <jeremie.galarneau@efficios.com>
Fri, 30 Apr 2021 22:01:46 +0000 (18:01 -0400)
commit741e787bf03338ec74a1df3621c5bde4b13c4e17
treea33dbd262d3c6d51e0c4ac57ae6be8bf2ae5ff55
parent648fdbcca5a959cade4b7234f35ceaf0e533768f
Fix: consumerd: unbalanced subbuffer 'get' when checking operation availability

A WARN_ON in lttng-modules is hit in the get_subbuf ioctl, which
pointed to an unbalanced get/put pair when accessing the subbuffers
of a channel.

517716.168856] ------------[ cut here ]------------
[517716.171559] WARNING: CPU: 1 PID: 19313 at /home/efficios/git/lttng-modules/src/lib/ringbuffer/ring_buffer_frontend.c:1263 lib_ring_buffer_get_subbuf+0x24f/0x260 [lttng_lib_ring_buffer]
[517716.180096] Modules linked in: lttng_test(O) lttng_probe_x86_exceptions(O) lttng_probe_x86_irq_vectors(O) lttng_probe_writeback(O) lttng_probe_workqueue(O) lttng_probe_vmscan(O) lttng_probe_udp(O) lttng_probe_timer(O) lttng_probe_sunrpc(O) lttng_probe_statedump(O) lttng_probe_sock(O) lttng_probe_skb(O) lttng_probe_signal(O) lttng_probe_scsi(O) lttng_probe_sched(O) lttng_probe_regulator(O) lttng_probe_regmap(O) lttng_probe_rcu(O) lttng_probe_random(O) lttng_probe_printk(O) lttng_probe_power(O) lttng_probe_net(O) lttng_probe_napi(O) lttng_probe_module(O) lttng_probe_kmem(O) lttng_probe_jbd2(O) lttng_probe_irq(O) lttng_probe_i2c(O) lttng_probe_gpio(O) lttng_probe_ext4(O) lttng_probe_compaction(O) lttng_probe_btrfs(O) lttng_probe_block(O) lttng_counter_client_percpu_32_modular(O) lttng_counter_client_percpu_64_modular(O) lttng_counter(O) lttng_ring_buffer_event_notifier_client(O) lttng_ring_buffer_metadata_mmap_client(O) lttng_ring_buffer_client_mmap_overwrite(O)
[517716.180815]  lttng_ring_buffer_client_mmap_discard(O) lttng_ring_buffer_metadata_client(O) lttng_ring_buffer_client_overwrite(O) lttng_ring_buffer_client_discard(O) lttng_tracer(O) lttng_statedump(O) lttng_wrapper(O) lttng_uprobes(O) lttng_clock(O) lttng_kprobes(O) lttng_lib_ring_buffer(O) lttng_kretprobes(O) [last unloaded: lttng_wrapper]
[517716.213228] CPU: 1 PID: 19313 Comm: lttng-consumerd Tainted: G           O      5.11.2 #80
[517716.215573] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[517716.220341] RIP: 0010:lib_ring_buffer_get_subbuf+0x24f/0x260 [lttng_lib_ring_buffer]
[517716.222579] Code: 50 f0 ff 00 0f 0b 49 03 5f 28 44 8b 85 80 00 00 00 49 8b 77 30 45 85 c0 48 89 d9 0f 85 4f ff ff ff e9 25 ff ff ff f0 ff 45 00 <0f> 0b b8 f0 ff ff ff e9 a6 fe ff ff 0f 1f 44 00 00 0f 1f 44 00 00
[517716.227610] RSP: 0018:ffffbafd09023e88 EFLAGS: 00010202
[517716.229147] RAX: 0000000000000000 RBX: ffff9906ed069a00 RCX: ffff9905c4e4a400
[517716.231186] RDX: ffffdafcffc4ec90 RSI: 0000000000200000 RDI: ffffdafcffc4e9f0
[517716.233265] RBP: ffff9905c4e4a400 R08: 0000000000300000 R09: 0000000000200000
[517716.235284] R10: 0000000000200000 R11: 0000000000000000 R12: 0000000000000000
[517716.237333] R13: 0000000000000000 R14: 000000000000005e R15: 0000000000000000
[517716.239360] FS:  00007ff327fff700(0000) GS:ffff9905a7a40000(0000) knlGS:0000000000000000
[517716.241634] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[517716.243262] CR2: 000055b91cf07730 CR3: 000000076f45e003 CR4: 00000000001706e0
[517716.245316] Call Trace:
[517716.246281]  lib_ring_buffer_ioctl+0x181/0x300 [lttng_lib_ring_buffer]
[517716.248301]  lttng_stream_ring_buffer_ioctl+0x1a3/0x200 [lttng_tracer]
[517716.252621]  __x64_sys_ioctl+0x8e/0xd0
[517716.253931]  do_syscall_64+0x33/0x80
[517716.255016]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[517716.256448] RIP: 0033:0x7ff3372f46d7
[517716.257586] Code: b3 66 90 48 8b 05 b1 47 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 81 47 2d 00 f7 d8 64 89 01 48
[517716.262472] RSP: 002b:00007ff327ffe2c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[517716.264634] RAX: ffffffffffffffda RBX: 00007ff310002740 RCX: 00007ff3372f46d7
[517716.266674] RDX: 0000000000000000 RSI: 000000000000f605 RDI: 000000000000005e
[517716.268713] RBP: 00007ff327ffe310 R08: 00007ff310002870 R09: a002000000000000
[517716.270732] R10: 000055992b0a6530 R11: 0000000000000246 R12: 000055992c47da70
[517716.272768] R13: 00007ff318005e80 R14: 00007ff310002740 R15: 000055992b0a6528
[517716.274800] irq event stamp: 4526705
[517716.275897] hardirqs last  enabled at (4526713): [<ffffffff9016a474>] console_unlock+0x4b4/0x5b0
[517716.278320] hardirqs last disabled at (4526722): [<ffffffff9016a3d0>] console_unlock+0x410/0x5b0
[517716.280759] softirqs last  enabled at (4526658): [<ffffffff9120030f>] __do_softirq+0x30f/0x432
[517716.285125] softirqs last disabled at (4526653): [<ffffffff91001052>] asm_call_irq_on_stack+0x12/0x20
[517716.287648] ---[ end trace 506e55b312b731bf ]---

The check for the availability of the 'get_next_check_metadata'
operation attempts to use the operation at the creation of the metadata
stream. Most of the time this occurs before any metadata could be
generated.

However, the check will sometimes (very rarely) occur after the
generation of some metadata causing the 'get' to succeed and,
consequently, a subbuffer to be acquired. In those cases, the subbuffer
must be released immediately.

Fixes #1313

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I906dca7d83ce103c009aa477ae5881145e4aa081
src/common/kernel-consumer/kernel-consumer.c
This page took 0.030799 seconds and 4 git commands to generate.