ubuntu_lttng_smoke_test failed on z-hwe: Kernel tracer not available

Bug #1677126 reported by Po-Hsu Lin on 2017-03-29
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux-hwe-edge (Ubuntu)
Medium
Colin Ian King
Xenial
Undecided
Unassigned
lttng-modules (Ubuntu)
Medium
Colin Ian King
Xenial
Undecided
Unassigned

Bug Description

== SRU REQUEST [Xenial] ==

We are getting lttng module build failures on the HWE 4.10.0 kernel because we are missing the 4.9 and 4.10 compatibility patches to build for a 4.10 kernel.

== Fix ==

Apply minimal set of upstream patches to enable 4.9 + 4.10 builds:

769b62a02f62ff8db93f109d9f63a1df6ea9990b
     Fix-unregister-cpu-hotplug-notifier-on-buffer-alloc-.patch

489de24bfb835022b64c2e71d717eaf333ab3633
     Add-load-unload-messages-to-kernel-log.patch

3e86016420272ce5ef0139ad52f20c83305f0f15
     Fix-update-scsi-instrumentation-for-4.7-kernels.patch

f3166f27f5e2d2210cec32d68c277940a7473281
     btrfs-instrumentation-update-to-4.10-kernel.patch

507143bc5de50c0e5493d63fb5c300fa42326842
     timer-instrumentation-adapt-to-ktime_t-without-union.patch

1e36732678d7cc650940b4508031acf2f6ffcd1b
     Adapt-lttng-modules-to-Linux-4.10-cpu-hotplug-state-.patch

da3b99a6386302158785e1f8fd1679c106850d0e
     Fix: only include linux/cpuhotplug.h for kernels >= 4.10

ce4a2f0c273d4077c6eb9e6e0f28379ddaf61382
     Fix: 4.10 hotplug adaptation backward compat

== Testing ==

Without the fix, lttng modules won't install and build on HWE 4.10 kernels. With the fix, the lttng modules build and also pass the ubuntu kernel team autotest lttng smoke tests.

Should be tested with xenial 4.4 kernel to ensure backward compatibility is not broken on the default Xenial kernels

== Regression potential ==

Can potential break lttng.

-------------------------------------------------------------------------

Test failed with "Kernel tracer not available"

root@michael:/home/ubuntu/autotest-client-tests/ubuntu_lttng_smoke_test# ./ubuntu_lttng_smoke_test.sh
== lttng smoke test of session create/destroy ==
Session test-kernel-session created.
Traces will be written in /tmp/lttng-kernel-trace-12675-session
PASSED (lttng create)
Session test-kernel-session destroyed
PASSED (lttng destroy)

== lttng smoke test list kernel events ==
Error: Unable to list kernel events: Kernel tracer not available
Error: Command error
FAILED (lttng list --kernel)
FAILED (lttng list --kernel more output expected)

== lttng smoke test trace open/close system calls ==
Session test-kernel-session created.
Traces will be written in /tmp/lttng-kernel-trace-12675-session
PASSED (lttng create)
Error: Event open: Kernel tracer not available (channel channel0, session test-kernel-session)
Error: Event openat: Kernel tracer not available (channel channel0, session test-kernel-session)
Error: Event close: Kernel tracer not available (channel channel0, session test-kernel-session)
FAILED (lttng enable-event)
Session test-kernel-session destroyed

== lttng smoke test trace context switches ==
Session test-kernel-session created.
Traces will be written in /tmp/lttng-kernel-trace-12675-session
PASSED (lttng create)
Error: Event sched_switch: Kernel tracer not available (channel channel0, session test-kernel-session)
FAILED (lttng enable-event)
Session test-kernel-session destroyed

Summary: 4 passed, 4 failed

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: linux-image-4.10.0-14-generic 4.10.0-14.16~16.04.1
ProcVersionSignature: Ubuntu 4.10.0-14.16~16.04.1-generic 4.10.3
Uname: Linux 4.10.0-14-generic x86_64
ApportVersion: 2.20.1-0ubuntu2.5
Architecture: amd64
Date: Wed Mar 29 06:08:00 2017
SourcePackage: linux-hwe-edge
UpgradeStatus: No upgrade log present (probably fresh install)

Po-Hsu Lin (cypressyew) wrote :
Changed in linux-hwe-edge (Ubuntu):
importance: Undecided → Medium
assignee: nobody → Colin Ian King (colin-king)
Colin Ian King (colin-king) wrote :

sudo /usr/bin/lttng-sessiond -vvv shows us the cause:

DEBUG1 - 08:54:51.384370 [14445/14475]: Processing client command 14 (in process_client_msg() at main.c:2989)
modprobe: FATAL: Module lttng-tracer not found in directory /lib/modules/4.10.0-14-generic
Error: Unable to load required module lttng-tracer
DEBUG1 - 08:54:51.387309 [14445/14475]: Failed to open /proc/lttng (in init_kernel_tracer() at main.c:2721)
DEBUG1 - 08:54:51.390165 [14445/14475]: Modprobe removal successful lttng-kretprobes (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.392860 [14445/14475]: Modprobe removal successful lttng-kprobes (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.396010 [14445/14475]: Modprobe removal successful lttng-ftrace (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.398841 [14445/14475]: Modprobe removal successful lttng-types (in modprobe_remove_lttng() at modprobe.c:126)
Error: Unable to remove module lttng-ring-buffer-metadata-mmap-client
Error: Unable to remove module lttng-ring-buffer-client-mmap-overwrite
Error: Unable to remove module lttng-ring-buffer-client-mmap-discard
Error: Unable to remove module lttng-ring-buffer-metadata-client
Error: Unable to remove module lttng-ring-buffer-client-overwrite
Error: Unable to remove module lttng-ring-buffer-client-discard
Error: Unable to remove module lttng-lib-ring-buffer
Error: Unable to remove module lttng-tracer
Warning: No kernel tracer available
DEBUG1 - 08:54:51.422146 [14445/14475]: Missing llm structure. Allocating one. (in process_client_msg() at main.c:4037)
DEBUG1 - 08:54:51.422168 [14445/14475]: Sending response (size: 16, retcode: Kernel tracer not available) (in thread_manage_clients() at main.c:4456)
DEBUG1 - 08:54:51.422197 [14445/14475]: Clean command context structure (in clean_command_ctx() at main.c:829)
DEBUG1 - 08:54:51.422206 [14445/14475]: Accepting client command ... (in thread_manage_clients() at main.c:4310)

Colin Ian King (colin-king) wrote :

Oops, wrong log. Here is what I meant to paste:

DEBUG1 - 08:54:51.384339 [14445/14475]: Receiving data from client ... (in thread_manage_clients() at main.c:4407)
DEBUG1 - 08:54:51.384370 [14445/14475]: Processing client command 14 (in process_client_msg() at main.c:2989)
modprobe: FATAL: Module lttng-tracer not found in directory /lib/modules/4.10.0-14-generic
Error: Unable to load required module lttng-tracer
DEBUG1 - 08:54:51.387309 [14445/14475]: Failed to open /proc/lttng (in init_kernel_tracer() at main.c:2721)
DEBUG1 - 08:54:51.390165 [14445/14475]: Modprobe removal successful lttng-kretprobes (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.392860 [14445/14475]: Modprobe removal successful lttng-kprobes (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.396010 [14445/14475]: Modprobe removal successful lttng-ftrace (in modprobe_remove_lttng() at modprobe.c:126)
DEBUG1 - 08:54:51.398841 [14445/14475]: Modprobe removal successful lttng-types (in modprobe_remove_lttng() at modprobe.c:126)
Error: Unable to remove module lttng-ring-buffer-metadata-mmap-client
Error: Unable to remove module lttng-ring-buffer-client-mmap-overwrite
Error: Unable to remove module lttng-ring-buffer-client-mmap-discard
Error: Unable to remove module lttng-ring-buffer-metadata-client
Error: Unable to remove module lttng-ring-buffer-client-overwrite
Error: Unable to remove module lttng-ring-buffer-client-discard
Error: Unable to remove module lttng-lib-ring-buffer
Error: Unable to remove module lttng-tracer

Colin Ian King (colin-king) wrote :
Download full text (4.5 KiB)

$ cat /var/lib/dkms/lttng-modules/2.8.0/build/make.log
DKMS make.log for lttng-modules-2.8.0 for kernel 4.10.0-14-generic (x86_64)
Wed Mar 29 08:57:24 UTC 2017
make: Entering directory '/usr/src/linux-headers-4.10.0-14-generic'
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-client-discard.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-client-overwrite.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-metadata-client.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-client-mmap-discard.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-client-mmap-overwrite.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-ring-buffer-metadata-mmap-client.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-clock.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-events.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-abi.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-probes.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-pid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-procname.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-prio.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-nice.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-vpid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-tid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-vtid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-ppid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-vppid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-cpu-id.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-interruptible.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-need-reschedule.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-calibrate.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-hostname.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/wrapper/random.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/probes/lttng.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/wrapper/trace-clock.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/wrapper/page_alloc.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-tracker-pid.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-filter.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-filter-interpreter.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-filter-specialize.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-filter-validator.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/probes/lttng-probe-user.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-syscalls.o
  CC [M] /var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-perf-counters.o
/var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-perf-counters.c: In function ‘lttng_destroy_perf_counter_field’:
/var/lib/dkms/lttng-modules/2.8.0/build/lttng-context-perf-counters.c:102:2: error: implicit declaration of function ‘...

Read more...

description: updated
description: updated
Changed in linux-hwe-edge (Ubuntu):
status: New → In Progress
Changed in lttng-modules (Ubuntu):
status: New → In Progress
importance: Undecided → Medium
assignee: nobody → Colin Ian King (colin-king)
Chris J Arges (arges) wrote :

Colin,
Can you confirm that lttng-modules in zesty (2.9.0-1ubuntu1) works with the 4.10 kernel?
Thanks

Po-Hsu Lin (cypressyew) wrote :

Tested with 4.10.0-15 on Zesty zKVM

module (2.9.0-1ubuntu1) works fine on it with the test suite

Test log:
ubuntu@s2lp6g003:~/autotest/client/tests/ubuntu_lttng_smoke_test$ sudo ./ubuntu_lttng_smoke_test.sh
== lttng smoke test of session create/destroy ==
Spawning a session daemon
Session test-kernel-session created.
Traces will be written in /tmp/lttng-kernel-trace-22732-session
PASSED (lttng create)
Session test-kernel-session destroyed
PASSED (lttng destroy)

== lttng smoke test list kernel events ==
PASSED (lttng list --kernel)

lttng smoke test trace open/close system calls SKIPPED for s390x

== lttng smoke test trace context switches ==
Session test-kernel-session created.
Traces will be written in /tmp/lttng-kernel-trace-22732-session
PASSED (lttng create)
Kernel event sched_switch created in channel channel0
PASSED (lttng enable-event)
Tracing started for session test-kernel-session
PASSED (lttng start)
Waiting for data availability.
[warning] 2884 events discarded, please refer to the documentation on channel configuration.
Tracing stopped for session test-kernel-session
PASSED (lttng stop)
Session test-kernel-session destroyed
PASSED (lttng destroy)
[warning] Tracer discarded 2884 events between [10:14:07.143437366] and [10:14:07.237056267] in trace UUID de3fef3f9f7a98408b3b626436f1e6c7, at path: "/tmp/lttng-kernel-trace-22732-session/kernel", within stream id 0, at relative path: "channel0_0". You should consider recording a new trace with larger buffers or with fewer events enabled.
Found 31034 dd and 56871 context switches
PASSED (simple system call tracing with babeltrace)

Summary: 8 passed, 0 failed

Colin Ian King (colin-king) wrote :

Tested Zesty lttng-modules 2.9.0-1ubuntu1 on 4.10.0-15-generic #17 with ubuntu_lttng_smoke_test from the ubuntu autotest client tests. Passed OK. Looks good to me.

Hello Po-Hsu, or anyone else affected,

Accepted lttng-modules into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/lttng-modules/2.8.0-1ubuntu1~16.04.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Changed in lttng-modules (Ubuntu Xenial):
status: New → Fix Committed
tags: added: verification-needed
Colin Ian King (colin-king) wrote :

Tested lttng-modules 2.8.0-1ubuntu1~16.04.2 on xenial with kernel 4.4.0-72-generic #93 with the kernel team autotest client tests ubuntu_lttng_smoke tests and it passed.

tags: added: verification-done
removed: verification-needed

The verification of the Stable Release Update for lttng-modules has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Launchpad Janitor (janitor) wrote :

This bug was fixed in the package lttng-modules - 2.8.0-1ubuntu1~16.04.2

---------------
lttng-modules (2.8.0-1ubuntu1~16.04.2) xenial; urgency=medium

  * Fix builds on HWE 4.10 kernel (LP: #1677126)
    Backport the following upstream commits:
     0007-Fix-unregister-cpu-hotplug-notifier-on-buffer-alloc-.patch
     0008-Add-load-unload-messages-to-kernel-log.patch
     0009-Fix-update-scsi-instrumentation-for-4.7-kernels.patch
     0010-btrfs-instrumentation-update-to-4.10-kernel.patch
     0011-timer-instrumentation-adapt-to-ktime_t-without-union.patch
     0012-Adapt-lttng-modules-to-Linux-4.10-cpu-hotplug-state-.patch
     0013-Fix-only-include-linux-cpuhotplug.h-for-kernels-4.10.patch
     0014-Fix-4.10-hotplug-adaptation-backward-compat.patch

 -- Colin Ian King <email address hidden> Wed, 29 Mar 2017 14:05:08 +0100

Changed in lttng-modules (Ubuntu Xenial):
status: Fix Committed → Fix Released
Po-Hsu Lin (cypressyew) wrote :

Hello Colin,

I can see this issue on zVM(kernel02) with Yakkety (4.8.0-52), maybe we will need to patch this for lttng-modules on it as well?

05/03 00:35:44 DEBUG| utils:0116| Running '/home/ubuntu/autotest/client/tests/ubuntu_lttng_smoke_test/ubuntu_lttng_smoke_test.sh'
05/03 00:35:44 DEBUG| utils:0153| [stdout] == lttng smoke test of session create/destroy ==
05/03 00:36:01 DEBUG| utils:0153| [stdout] Spawning a session daemon
05/03 00:36:01 DEBUG| utils:0153| [stdout] Session test-kernel-session created.
05/03 00:36:01 DEBUG| utils:0153| [stdout] Traces will be written in /tmp/lttng-kernel-trace-27287-session
05/03 00:36:01 DEBUG| utils:0153| [stdout] PASSED (lttng create)
05/03 00:36:01 DEBUG| utils:0153| [stdout] Session test-kernel-session destroyed
05/03 00:36:01 DEBUG| utils:0153| [stdout] PASSED (lttng destroy)
05/03 00:36:01 DEBUG| utils:0153| [stdout]
05/03 00:36:01 DEBUG| utils:0153| [stdout] == lttng smoke test list kernel events ==
05/03 00:36:01 ERROR| utils:0153| [stderr] Error: Unable to list kernel events: Kernel tracer not available
05/03 00:36:01 ERROR| utils:0153| [stderr] Error: Command error
05/03 00:36:01 DEBUG| utils:0153| [stdout] FAILED (lttng list --kernel)
05/03 00:36:01 DEBUG| utils:0153| [stdout] FAILED (lttng list --kernel more output expected)
05/03 00:36:01 DEBUG| utils:0153| [stdout]
05/03 00:36:01 DEBUG| utils:0153| [stdout] lttng smoke test trace open/close system calls SKIPPED for s390x
05/03 00:36:01 DEBUG| utils:0153| [stdout]
05/03 00:36:01 DEBUG| utils:0153| [stdout] == lttng smoke test trace context switches ==
05/03 00:36:01 DEBUG| utils:0153| [stdout] Session test-kernel-session created.
05/03 00:36:01 DEBUG| utils:0153| [stdout] Traces will be written in /tmp/lttng-kernel-trace-27287-session
05/03 00:36:01 DEBUG| utils:0153| [stdout] PASSED (lttng create)
05/03 00:36:01 ERROR| utils:0153| [stderr] Error: Event sched_switch: Kernel tracer not available (channel channel0, session test-kernel-session)

Colin Ian King (colin-king) wrote :

I believe this is a different issue. Can you create a new bug report and assign that to me. Thanks.

Po-Hsu Lin (cypressyew) wrote :

For comment #13 and #14, Colin had a look on this, and it can't be reproduced.

I will open a new issue for that in the future if it's not working.
Thanks.

Changed in lttng-modules (Ubuntu):
status: In Progress → Fix Released
Changed in linux-hwe-edge (Ubuntu):
status: In Progress → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers