[lttng-dev] lttng create call trace on kernel 4.19

Fri Oct 12 12:21:18 EDT 2018

Hi Dengke,

We were able to reproduce it. This is not related to yocto and seems to be
related to a change introduced in the 4.19 kernel.

If you are not interested in kernel tracing you can pass the --no-kernel flag to
lttng-sessiond to prevent the loading of the kernel modules.

We are looking into the root problem and possible fix on either the kernel side
or ours.

Thanks for reporting the issue. We will keep you updated.

Cheers

On Fri, Oct 12, 2018 at 11:10:09AM -0400, Mathieu Desnoyers wrote:
> ----- On Oct 11, 2018, at 9:21 PM, Dengke Du dengke.du at windriver.com wrote:
> 
> > On 2018年10月11日 21:22, Jonathan Rajotte-Julien wrote:
> >> Hi,
> >>
> >> On Thu, Oct 11, 2018 at 02:00:11PM +0800, Dengke Du wrote:
> >>> Hi all
> >>>
> >>> When I create a local trace session, meeting a call trace:
> >>>
> >>> uname -a:
> >>>
> >>> Linux qemux86-64 4.19.0-rc7-yoctodev-standard #1 SMP PREEMPT Thu Oct 11
> >>> 03:32:48 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
> >> Which yocto branch, recipes(for kernel, lttng-tools, lttng-modules) and target?
> >>
> >> Which version of lttng-modules are you using?
> 
> Please answer the questions above as well.
> 
> Thanks,
> 
> Mathieu
> 
> 
> >>
> >> Any modification to the kernel?
> > 
> > Yocto: master branch
> > Kernel: linux-yocto-dev
> > 
> > phenomenon 1:
> >     linux-yocto was ok (v4.18)
> > phenomenon 2:
> >     linux-yocto-dev was not ok (v4.19)
> > 
> > Maybe some kernel commit breaks it.
> > 
> >>
> >>> lttng create trace_session --live -U net://127.0.0.1
> >>>
> >>> ----------------------------------------------------------------------------------------------------------
> >>>
> >>> [  222.390601] lttng_kretprobes: loading out-of-tree module taints kernel.
> >>> [  223.550725] BUG: unable to handle kernel paging request at
> >>> 0000111400001158
> >>> [  223.551661] PGD 0 P4D 0
> >>> [  223.552476] Oops: 0000 [#1] PREEMPT SMP PTI
> >>> [  223.553170] CPU: 0 PID: 500 Comm: modprobe Tainted: G O
> >>> 4.19.0-rc7-yoctodev-standard #1
> >>> [  223.553892] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> >>> rel-1.11.2-0-gf9626ccb91-prebuilt.qemu-project.org 04/01/2014
> >>> [  223.556619] RIP: 0010:lttng_tracepoint_notify+0x16e/0x200 [lttng_tracer]
> >>> [  223.557751] Code: eb bd 48 39 c1 0f 85 a3 00 00 00 49 8b 55 10 41 83 c4
> >>> 01 44 39 a2 8c 02 00 00 76 a3 48 8b 92 90 02 00 00 49 63 c4 48 8b 0c c2 <4c>
> >>> 8b 31 48 89 4d d0 4c 89 f7 e8 90
> >>> [  223.559769] RSP: 0000:ffffa39a00373bc0 EFLAGS: 00000206
> >>> [  223.560303] RAX: 0000000000000000 RBX: ffff9b3dd45a83a0 RCX:
> >>> 0000111400001158
> >>> [  223.560959] RDX: ffffffffc01b9048 RSI: 0000000000000001 RDI:
> >>> ffffffffc02f1100
> >>> [  223.561579] RBP: ffffa39a00373bf0 R08: 0000000000000064 R09:
> >>> ffff9b3ddec01600
> >>> [  223.562388] R10: ffffffffc0287411 R11: ffffffff98dc9660 R12:
> >>> 0000000000000000
> >>> [  223.563008] R13: ffff9b3dd45a83a0 R14: ffffa39a00373e78 R15:
> >>> 0000000000000002
> >>> [  223.563905] FS:  00007fb049015740(0000) GS:ffff9b3ddf200000(0000)
> >>> knlGS:0000000000000000
> >>> [  223.564941] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >>> [  223.565501] CR2: 0000111400001158 CR3: 0000000014586000 CR4:
> >>> 00000000000006f0
> >>> [  223.566450] Call Trace:
> >>> [  223.568367]  ? lttng_kernel_tracepoint_add+0x50/0xc0 [lttng_tracer]
> >>> [  223.569932]  register_tracepoint_module_notifier+0x57/0x80
> >>> [  223.571309]  ? 0xffffffffc0309000
> >>> [  223.572187]  lttng_tracepoint_init+0x45/0xbf9 [lttng_tracer]
> >>> [  223.573125]  lttng_events_init+0x40/0x1cc [lttng_tracer]
> >>> [  223.573820]  ? 0xffffffffc0309000
> >>> [  223.574237]  do_one_initcall+0x53/0x1fe
> >>> [  223.574682]  ? __vunmap+0x8e/0xc0
> >>> [  223.575196]  ? kmem_cache_alloc_trace+0xfc/0x1d0
> >>> [  223.575684]  ? do_init_module+0x27/0x210
> >>> [  223.576285]  do_init_module+0x60/0x210
> >>> [  223.576702]  load_module+0x2406/0x2570
> >>> [  223.577140]  ? vfs_read+0x115/0x140
> >>> [  223.577611]  ? vfs_read+0x115/0x140
> >>> [  223.578034]  __se_sys_finit_module+0xc3/0xe0
> >>> [  223.578581]  ? __se_sys_finit_module+0xc3/0xe0
> >>> [  223.579135]  __x64_sys_finit_module+0x1a/0x20
> >>> [  223.579627]  do_syscall_64+0x4d/0xf0
> >>> [  223.580071]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
> >>> [  223.580837] RIP: 0033:0x7fb049107569
> >>> [  223.581286] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48
> >>> 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48>
> >>> 3d 01 f0 ff ff 73 01 c3 48 8b 08
> >>> [  223.583210] RSP: 002b:00007ffc80620498 EFLAGS: 00000246 ORIG_RAX:
> >>> 0000000000000139
> >>> [  223.583958] RAX: ffffffffffffffda RBX: 000055931b680b70 RCX:
> >>> 00007fb049107569
> >>> [  223.584677] RDX: 0000000000000000 RSI: 000055931b67734e RDI:
> >>> 000000000000000a
> >>> [  223.585372] RBP: 0000000000000000 R08: 0000000000000000 R09:
> >>> 000055931b680b70
> >>> [  223.586008] R10: 000000000000000a R11: 0000000000000246 R12:
> >>> 000055931b67734e
> >>> [  223.586696] R13: 0000000000040000 R14: 0000000000000000 R15:
> >>> 0000000000000000
> >>> [  223.587620] Modules linked in: lttng_tracer(O+) lttng_statedump(O)
> >>> lttng_ftrace(O) lttng_kprobes(O) lttng_clock(O) lttng_lib_ring_buffer(O)
> >>> lttng_kretprobes(O) deflate twofish_geneb
> >>> [  223.597615] CR2: 0000111400001158
> >>> [  223.614673] ---[ end trace 514884c3611a01af ]---
> >>> [  223.615793] RIP: 0010:lttng_tracepoint_notify+0x16e/0x200 [lttng_tracer]
> >>> [  223.616604] Code: eb bd 48 39 c1 0f 85 a3 00 00 00 49 8b 55 10 41 83 c4
> >>> 01 44 39 a2 8c 02 00 00 76 a3 48 8b 92 90 02 00 00 49 63 c4 48 8b 0c c2 <4c>
> >>> 8b 31 48 89 4d d0 4c 89 f7 e8 90
> >>> [  223.624684] RSP: 0000:ffffa39a00373bc0 EFLAGS: 00000206
> >>> [  223.625177] RAX: 0000000000000000 RBX: ffff9b3dd45a83a0 RCX:
> >>> 0000111400001158
> >>> [  223.626102] RDX: ffffffffc01b9048 RSI: 0000000000000001 RDI:
> >>> ffffffffc02f1100
> >>> [  223.632541] RBP: ffffa39a00373bf0 R08: 0000000000000064 R09:
> >>> ffff9b3ddec01600
> >>> [  223.633110] R10: ffffffffc0287411 R11: ffffffff98dc9660 R12:
> >>> 0000000000000000
> >>> [  223.637690] R13: ffff9b3dd45a83a0 R14: ffffa39a00373e78 R15:
> >>> 0000000000000002
> >>> [  223.641583] FS:  00007fb049015740(0000) GS:ffff9b3ddf200000(0000)
> >>> knlGS:0000000000000000
> >>> [  223.642238] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >>> [  223.642906] CR2: 00007f6eae3e4b58 CR3: 0000000014586000 CR4:
> >>> 00000000000006f0
> >>> 2018 Oct 11 05:37:07 qemux86-64 [  223.550725] BUG: unable to handle kernel
> >>> paging request at 0000111400001158
> >>> 2018 Oct 11 05:37:07 qemux86-64 BUG: unable to handle kernel paging request
> >>> at 0000111400001158
> >>>
> >>> ----------------------------------------------------------------------------------------------------------
> >>>
> >>> When I type that command again:
> >>>
> >>> ----------------------------------------------------------------------------------------------------------
> >>>
> >>> Spawning a session daemon
> >>> Error: Session daemon terminated with an error (exit status: 1)
> >>> Error: Problem occurred while launching session daemon
> >>> (/usr/bin/lttng-sessiond)
> >>> Error: Command error
> >>>
> >>> ----------------------------------------------------------------------------------------------------------
> >>>
> >>>
> >>> _______________________________________________
> >>> lttng-dev mailing list
> >>> lttng-dev at lists.lttng.org
> >>> https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> > 
> > _______________________________________________
> > lttng-dev mailing list
> > lttng-dev at lists.lttng.org
> > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> 
> -- 
> Mathieu Desnoyers
> EfficiOS Inc.
> http://www.efficios.com

-- 
Jonathan Rajotte-Julien
EfficiOS