From: Jérémie Galarneau Date: Thu, 29 Apr 2021 20:17:45 +0000 (-0400) Subject: Fix: consumerd: unbalanced subbuffer 'get' when checking operation availability X-Git-Tag: v2.11.7~6 X-Git-Url: https://git.lttng.org./?a=commitdiff_plain;h=852a753fee8c0d561a41b99ed98ae1a123a0f899;p=lttng-tools.git 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): [] console_unlock+0x4b4/0x5b0 [517716.278320] hardirqs last disabled at (4526722): [] console_unlock+0x410/0x5b0 [517716.280759] softirqs last enabled at (4526658): [] __do_softirq+0x30f/0x432 [517716.285125] softirqs last disabled at (4526653): [] 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 Change-Id: Ic4f3deb6fa665a13e3673fd859b23d7ef803f963 --- diff --git a/src/common/kernel-consumer/kernel-consumer.c b/src/common/kernel-consumer/kernel-consumer.c index 2b8e09140..bcdf2c02f 100644 --- a/src/common/kernel-consumer/kernel-consumer.c +++ b/src/common/kernel-consumer/kernel-consumer.c @@ -1611,8 +1611,15 @@ int put_next_subbuffer(struct lttng_consumer_stream *stream, static bool is_get_next_check_metadata_available(int tracer_fd) { - return kernctl_get_next_subbuf_metadata_check(tracer_fd, NULL) != - -ENOTTY; + const int ret = kernctl_get_next_subbuf_metadata_check(tracer_fd, NULL); + const bool available = ret != -ENOTTY; + + if (ret == 0) { + /* get succeeded, make sure to put the subbuffer. */ + kernctl_put_subbuf(tracer_fd); + } + + return available; } static