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, 7 May 2021 17:47:51 +0000 (13:47 -0400)
commit0aeedd20e4193fc4c81da2a169a0caa7bf51fe53
treea33dbd262d3c6d51e0c4ac57ae6be8bf2ae5ff55
parentf703a68dfbed1e0ba84107b918c8f62fcd26e3ed
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.027769 seconds and 5 git commands to generate.