Project

General

Profile

Actions

Bug #1173

closed

yocto 2.6.1(pre-release) + lttng no kernel logging?

Added by Robert Berger almost 3 years ago. Updated almost 3 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Target version:
-
Start date:
01/22/2019
Due date:
% Done:

0%

Estimated time:

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

config (190 KB) config kernel config of "unhappy" kernel Robert Berger, 01/22/2019 10:28 AM
Actions #1

Updated by Jonathan Rajotte Julien almost 3 years ago

  • Description updated (diff)
Actions #2

Updated by Jonathan Rajotte Julien almost 3 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

Actions #3

Updated by Robert Berger almost 3 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

Actions #4

Updated by Robert Berger almost 3 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)
Actions #5

Updated by Robert Berger almost 3 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.html

We 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
Actions #6

Updated by Robert Berger almost 3 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.

Actions #7

Updated by Robert Berger almost 3 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:

https://github.com/RobertBerger/meta-mainline/blob/thud-training-v4.19.x/multi-v7-ml/recipes-kernel/linux/linux-yocto-custom_4.19.13.bb

plus this patch:

https://github.com/RobertBerger/meta-mainline/blob/thud-training-v4.19.x/multi-v7-ml/recipes-kernel/linux/patch/4.19.x/patches/phyBOARD-MIRA/patches-multi-v7-defconfig/0001-revert-patch-e7e73b10d690c5352cb11b1941a09e4f3dc4c8c.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.

Actions #8

Updated by Robert Berger almost 3 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;)

Actions #9

Updated by Robert Berger almost 3 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.

Actions #10

Updated by Robert Berger almost 3 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
Actions #11

Updated by Jonathan Rajotte Julien almost 3 years ago

  • Status changed from Feedback to Resolved
Actions

Also available in: Atom PDF