Bug #1173
closedyocto 2.6.1(pre-release) + lttng no kernel logging?
0%
Description
hardware: i.mx6 quad (Arm v7)
components used:
poky/branch: https://github.com/RobertBerger/poky/tree/2019-01-16-thud-2.6.1-pre-release
layer, which adds 4.19.13 kernel + new lttng components:
https://github.com/RobertBerger/meta-mainline/tree/thud-training-v4.19.x/multi-v7-ml
kernel:
target# uname -a Linux multi-v7-ml 4.19.13-custom-ml-debug #1 SMP Wed Jan 16 20:05:50 UTC 2019 armv7l armv7l armv7l GNU/Linux
target# gcc --version gcc (GCC) 8.2.0 Copyright (C) 2018 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
host# bitbake-layers show-recipes | grep -A1 lttng lttng-modules: multi-v7-ml 2.10.8 -- lttng-tools: multi-v7-ml 2.10.5 -- lttng-ust: multi-v7-ml 2:2.10.2
--------------------------------------
Session on serial console (so we can see kernel complaints as well) on target:
root@multi-v7-ml:/# export SESSION="test_session" root@multi-v7-ml:/# lttng create ${SESSION} Spawning a session daemon [ 81.444493] lttng_kretprobes: loading out-of-tree module taints kernel. [ 81.451767] lttng_kretprobes: section 4 reloc 5 sym 'strlen': relocation 28 out of range (0xbf0700a0 -> 0xc10a761c) Session test_session created. Traces will be written in /home/root/lttng-traces/test_session-20190122-114319 root@multi-v7-ml:/# lsmod Module Size Used by rtc_da9063 16384 0 da9062_core 16384 0 rtc_snvs 16384 1 root@multi-v7-ml:/# lttng list Available tracing sessions: 1) test_session (/home/root/lttng-traces/test_session-20190122-114319) [inactive] Trace path: /home/root/lttng-traces/test_session-20190122-114319 Use lttng list <session_name> for more details root@multi-v7-ml:/# lttng enable-event --kernel sched_switch,sched_process_fork [ 150.804796] lttng_kretprobes: section 4 reloc 5 sym 'strlen': relocation 28 out of range (0xbf0770a0 -> 0xc10a761c) Error: Event sched_switch: Kernel tracer not available (channel channel0, session test_session) [ 150.971757] lttng_kretprobes: section 4 reloc 5 sym 'strlen': relocation 28 out of range (0xbf07e0a0 -> 0xc10a761c) Error: Event sched_process_fork: Kernel tracer not available (channel channel0, session test_session)
Kernel tracer nor available - so I guess there is no point to try more stuff here.
What would you suggest?
root@multi-v7-ml:/# lttng list ${SESSION} Tracing session test_session: [inactive] Trace path: /home/root/lttng-traces/test_session-20190122-114319 root@multi-v7-ml:/# lttng start Error: No channel found in the session
Am I doing something wrong or do I need some kernel/lttng_modules fixes?
BTW I tried first with whatever comes with my Yocto 2.6.1 pre-release and then upgraded to the latest and greatest lttng I could find on openembedded-core (master).
Files
Updated by Jonathan Rajotte Julien over 5 years ago
- Status changed from New to Feedback
Hi Robert,
Thanks for reporting this.
[ 81.451767] lttng_kretprobes: section 4 reloc 5 sym 'strlen': relocation 28 out of range (0xbf0700a0 -> 0xc10a761c)
Based on the output when trying to load the modules it might be a ARM related limitation, please take a look at this discussion [1].
They seem to mitigate the issue by enabling ARM_MODULE_PLTS/CONFIG_ARM_MODULE_PLTS [2].
[1] https://lore.kernel.org/patchwork/patch/878725/
[2] https://cateee.net/lkddb/web-lkddb/ARM_MODULE_PLTS.html
We might need to some work on our end to support PLT.
So far this not seems lttng-modules related. Could you try to build a "lighter" kernel and try and load lttmg-modules?
You can also try to load a "trivial" modules like Anders Roxell in [1].
I'm not fully used to yocto/bitbake, can you indicate to us how to retrieve the .config for the kernel? If we use the mentioned branch will we have a similar .config for the generated kernel?
BTW I tried first with whatever comes with my Yocto 2.6.1 pre-release and then upgraded to the latest and greatest lttng I could find on openembedded-core (master).
Did it work? It seems to imply it did not but I just want to make sure that I'm understanding correctly.
Cheers
Updated by Robert Berger over 5 years ago
Same here:
target# grep -i kprobe config
CONFIG_KPROBES=y CONFIG_HAVE_KPROBES=y CONFIG_KPROBE_EVENTS=y # CONFIG_KPROBES_SANITY_TEST is not set # CONFIG_ARM_KPROBES_TEST is not set
Updated by Robert Berger over 5 years ago
target# export SESSION="kprobe_test_session-3" target# lttng create ${SESSION} Session kprobe_test_session-3 created. Traces will be written in /home/root/lttng-traces/kprobe_test_session-3-20190122-125948 target# lttng enable-event --kernel sys_open --probe sys_open+0x0 [ 4676.412057] lttng_kretprobes: section 4 reloc 5 sym 'strlen': relocation 28 out of range (0xbf09a0a0 -> 0xc10a761c) Error: Event sys_open: Kernel tracer not available (channel channel0, session kprobe_test_session-3)
Updated by Robert Berger over 5 years ago
Jonathan Rajotte Julien wrote:
Based on the output when trying to load the modules it might be a ARM related limitation, please take a look at this discussion [1].
They seem to mitigate the issue by enabling ARM_MODULE_PLTS/CONFIG_ARM_MODULE_PLTS [2].
[1] https://lore.kernel.org/patchwork/patch/878725/
[2] https://cateee.net/lkddb/web-lkddb/ARM_MODULE_PLTS.htmlWe might need to some work on our end to support PLT.
As you suspected it's not set in my kernel:
root@multi-v7-ml:/tmp# cat config | grep PLT # CONFIG_ARM_MODULE_PLTS is not set
Updated by Robert Berger over 5 years ago
Jonathan Rajotte Julien wrote:
Did it work? It seems to imply it did not but I just want to make sure that I'm understanding correctly.
No it didn't work.
Updated by Robert Berger over 5 years ago
Jonathan Rajotte Julien wrote:
I'm not fully used to yocto/bitbake, can you indicate to us how to retrieve the .config for the kernel? If we use the mentioned branch will we have a similar .config for the generated kernel?
Well that's not so straight forward;)
The kernel is upstream 4.19.13:
repo: git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
Branch: linux-4.19.y
Commit: c04c050f5bf98845bfe22164b8a1503d696a6e26
as you can see here:
plus this patch:
which is only needed if you want to boot with a rootfs over nfs.
The kernel config is attached.
Hold your horses before you start further investigations. I am currently building a kernel with CONFIG_ARM_MODULE_PLTS=y to see if this works. Will let you know ASAP.
Updated by Robert Berger over 5 years ago
Robert Berger wrote:
Hold your horses before you start further investigations. I am currently building a kernel with CONFIG_ARM_MODULE_PLTS=y to see if this works. Will let you know ASAP.
I just built the kernel with CONFIG_ARM_MODULE_PLTS=y but did not yet rebuild the lttng modules with it.
This did not fix the issue.
I will bitbake everything including kernel+CONFIG_ARM_MODULE_PLTS and lttng modules and let you know.
This will take some time;)
Updated by Robert Berger over 5 years ago
My previous test (only building kernel with CONFIG_ARM_MODULE_PLTS=y) is not really valid, since there is a mixup of kernel versions due to the -dirty string.
Stay tuned for the bitbaking to finish and hopefully then I'll have a more consistent kernel+rootfs.
Updated by Robert Berger over 5 years ago
I think CONFIG_ARM_MODULE_PLTS=y was the problem.
Thanks a lot!
Here is the new session:
++ lsmod Module Size Used by bluetooth 602112 8 ecdh_generic 28672 1 bluetooth da9062_wdt 16384 0 rtc_da9063 16384 0 da9062_core 16384 0 rtc_snvs 16384 1 flexcan 20480 0 etnaviv 98304 0 gpu_sched 28672 1 etnaviv ++ lttng create test_session Spawning a session daemon [ 43.628497] lttng_kretprobes: loading out-of-tree module taints kernel. [ 43.905725] LTTng: Loaded modules v2.10.8 (KeKriek) Session test_session created. Traces will be written in /home/root/lttng-traces/test_session-20190122-162930 ++ lttng list --kernel Kernel events: ------------- lttng_logger (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_bias_level_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_bias_level_done (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_dapm_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_dapm_done (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_dapm_widget_power (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_dapm_widget_event_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) asoc_snd_soc_dapm_widget_event_done (loglevel: TRACE_EMERG (0)) (type: tracepoint) ... writeback_congestion_wait (loglevel: TRACE_EMERG (0)) (type: tracepoint) writeback_wait_iff_congested (loglevel: TRACE_EMERG (0)) (type: tracepoint) writeback_single_inode (loglevel: TRACE_EMERG (0)) (type: tracepoint) ++ lttng list Available tracing sessions: 1) test_session (/home/root/lttng-traces/test_session-20190122-162930) [inactive] Trace path: /home/root/lttng-traces/test_session-20190122-162930 Use lttng list <session_name> for more details ++ lttng enable-event --kernel sched_switch,sched_process_fork Kernel event sched_switch created in channel channel0 Kernel event sched_process_fork created in channel channel0 ++ lsmod Module Size Used by lttng_probe_writeback 36864 0 lttng_probe_workqueue 16384 0 lttng_probe_v4l2 16384 0 lttng_probe_vmscan 28672 0 lttng_probe_udp 16384 0 lttng_probe_timer 20480 0 lttng_probe_sunrpc 16384 0 lttng_probe_statedump 24576 0 lttng_probe_sock 16384 0 lttng_probe_skb 16384 0 lttng_probe_signal 16384 0 lttng_probe_scsi 20480 0 lttng_probe_sched 28672 0 lttng_probe_regulator 16384 0 lttng_probe_regmap 20480 0 lttng_probe_rcu 32768 0 lttng_probe_random 16384 0 lttng_probe_printk 16384 0 lttng_probe_power 16384 0 lttng_probe_net 16384 0 lttng_probe_napi 16384 0 lttng_probe_module 16384 0 lttng_probe_kmem 20480 0 lttng_probe_jbd2 20480 0 lttng_probe_irq 16384 0 lttng_probe_i2c 16384 0 lttng_probe_gpio 16384 0 lttng_probe_ext4 102400 0 lttng_probe_compaction 16384 0 lttng_probe_block 32768 0 lttng_probe_asoc 20480 0 lttng_ring_buffer_metadata_mmap_client 16384 0 lttng_ring_buffer_client_mmap_overwrite 20480 0 lttng_ring_buffer_client_mmap_discard 20480 0 lttng_ring_buffer_metadata_client 16384 0 lttng_ring_buffer_client_overwrite 20480 0 lttng_ring_buffer_client_discard 20480 2 lttng_tracer 786432 45 lttng_ring_buffer_client_mmap_discard,lttng_probe_udp,lttng_probe_compaction,lttng_probe_timer,lttng_probe_net,lttng_ring_buffer_metadata_mmap_client,lttng_probe_signal,lttng_probe_scsi,lttng_probe_regulator,lttng_probe_rcu,lttng_probe_workqueue,lttng_probe_block,lttng_probe_irq,lttng_probe_sunrpc,lttng_probe_ext4,lttng_probe_sock,lttng_probe_asoc,lttng_ring_buffer_metadata_client,lttng_probe_vmscan,lttng_ring_buffer_client_discard,lttng_probe_module,lttng_probe_i2c,lttng_probe_sched,lttng_probe_writeback,lttng_probe_skb,lttng_probe_printk,lttng_probe_jbd2,lttng_ring_buffer_client_mmap_overwrite,lttng_probe_v4l2,lttng_probe_regmap,lttng_probe_power,lttng_probe_statedump,lttng_probe_napi,lttng_probe_kmem,lttng_probe_gpio,lttng_probe_random,lttng_ring_buffer_client_overwrite lttng_statedump 20480 1 lttng_tracer lttng_ftrace 16384 1 lttng_tracer lttng_kprobes 16384 1 lttng_tracer lttng_clock 16384 5 lttng_ring_buffer_client_mmap_discard,lttng_tracer,lttng_ring_buffer_client_discard,lttng_ring_buffer_client_mmap_overwrite,lttng_ring_buffer_client_overwrite lttng_lib_ring_buffer 65536 24 lttng_ring_buffer_client_mmap_discard,lttng_probe_net,lttng_ring_buffer_metadata_mmap_client,lttng_probe_scsi,lttng_probe_regulator,lttng_probe_rcu,lttng_probe_irq,lttng_probe_sunrpc,lttng_probe_sock,lttng_probe_asoc,lttng_tracer,lttng_ring_buffer_metadata_client,lttng_ring_buffer_client_discard,lttng_probe_module,lttng_probe_i2c,lttng_probe_sched,lttng_probe_printk,lttng_ring_buffer_client_mmap_overwrite,lttng_probe_regmap,lttng_probe_power,lttng_probe_statedump,lttng_probe_napi,lttng_probe_random,lttng_ring_buffer_client_overwrite lttng_kretprobes 16384 1 lttng_tracer bluetooth 602112 8 ecdh_generic 28672 1 bluetooth da9062_wdt 16384 0 rtc_da9063 16384 0 da9062_core 16384 0 rtc_snvs 16384 1 flexcan 20480 0 etnaviv 98304 0 gpu_sched 28672 1 etnaviv ++ lttng list test_session Tracing session test_session: [inactive] Trace path: /home/root/lttng-traces/test_session-20190122-162930 === Domain: Kernel === Channels: ------------- - channel0: [enabled] Attributes: Event-loss mode: discard Sub-buffer size: 1048576 bytes Sub-buffer count: 4 Switch timer: inactive Read timer: 200000 µs Monitor timer: 1000000 µs Blocking timeout: 0 µs Trace file count: 1 per stream Trace file size: unlimited Output mode: splice Statistics: Discarded events: 0 Event rules: sched_process_fork (loglevel: TRACE_EMERG (0)) (type: tracepoint) [enabled] sched_switch (loglevel: TRACE_EMERG (0)) (type: tracepoint) [enabled] ++ lttng start Tracing started for session test_session ++ find /usr/share | xargs grep -s linux > /dev/null ++ lttng stop Waiting for data availability.. Tracing stopped for session test_session
Updated by Jonathan Rajotte Julien over 5 years ago
- Status changed from Feedback to Resolved