Fixed
Created: Sep 18, 2014
Updated: Dec 3, 2018
Resolved Date: Sep 23, 2014
Found In Version: 6.0.0.13
Fix Version: 6.0.0.13
Severity: Standard
Applicable for: Wind River Linux 6
Component/s: BSP - Async
The test was passed with Git on 09-Sep-2014, but failed with Git on 16-Sep-2014.
root@localhost:/opt/wr-test# ./main_test.sh -u xxx -s lttng2
/opt/wr-test/lib/lib.sh: line 111: sestatus: command not found
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
The test case list :
lttng2
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Start kts Case lttng2 at Fri Sep 19 02:14:16 UTC 2014 with duration 300 s
lttng_kretprobes: module is from the staging directory, the quality is unknown, you have been warned.
lttng_lib_ring_buffer: module is from the staging directory, the quality is unknown, you have been warned.
lttng_kprobes: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ftrace: module is from the staging directory, the quality is unknown, you have been warned.
lttng_statedump: module is from the staging directory, the quality is unknown, you have been warned.
lttng_tracer: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_irq: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_gpio: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_timer: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_workqueue: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_random: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_asoc: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_module: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_signal: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_kmem: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_skb: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_udp: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_statedump: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_ext4: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_sunrpc: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_net: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_compaction: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_jbd: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_sock: module is from the staging directory, the quality is unknown, you have been warned.
lttng_types: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_ext3: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_napi: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_vmscan: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_btrfs: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_rcu: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_writeback: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_printk: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_block: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_sched: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_jbd2: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_scsi: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_power: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_rpm: module is from the staging directory, the quality is unknown, you have been warned.
lttng_probe_regmap: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_metadata_mmap_client: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_metadata_client: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_client_overwrite: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_client_mmap_discard: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_client_discard: module is from the staging directory, the quality is unknown, you have been warned.
lttng_ring_buffer_client_mmap_overwrite: module is from the staging directory, the quality is unknown, you have been warned.
please wait \
=============================================
[ INFO: possible recursive locking detected ]
3.10.38-ltsi-WR6.0.0.0_standard #1 Tainted: G C
---------------------------------------------
lttng-sessiond/926 is trying to acquire lock:
(&(&p->alloc_lock)->rlock){+.+...}, at: [<7f01d560>] lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump]
but task is already holding lock:
(&(&p->alloc_lock)->rlock){+.+...}, at: [<7f01d4fc>] lttng_statedump_start+0x194/0x10e8 [lttng_statedump]
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(&(&p->alloc_lock)->rlock);
lock(&(&p->alloc_lock)->rlock);
*** DEADLOCK ***
May be due to missing lock nesting notation
3 locks held by lttng-sessiond/926:
#0: (sessions_mutex){+.+.+.}, at: [<7f0253e4>] lttng_session_enable+0x28/0x540 [lttng_tracer]
#1: (rcu_read_lock){.+.+..}, at: [<7f01d414>] lttng_statedump_start+0xac/0x10e8 [lttng_statedump]
#2: (&(&p->alloc_lock)->rlock){+.+...}, at: [<7f01d4fc>] lttng_statedump_start+0x194/0x10e8 [lttng_statedump]
stack backtrace:
CPU: 1 PID: 926 Comm: lttng-sessiond Tainted: G C 3.10.38-ltsi-WR6.0.0.0_standard #1
[<800170e0>] (unwind_backtrace+0x0/0xec) from [<800125ec>] (show_stack+0x20/0x24)
[<800125ec>] (show_stack+0x20/0x24) from [<806a698c>] (dump_stack+0x20/0x28)
[<806a698c>] (dump_stack+0x20/0x28) from [<8008771c>] (__lock_acquire+0x2ec/0x1b0c)
[<8008771c>] (__lock_acquire+0x2ec/0x1b0c) from [<80089620>] (lock_acquire+0x10c/0x214)
[<80089620>] (lock_acquire+0x10c/0x214) from [<806abfe8>] (_raw_spin_lock+0x48/0x58)
[<806abfe8>] (_raw_spin_lock+0x48/0x58) from [<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump])
[<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump]) from [<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer])
[<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer]) from [<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer])
[<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer]) from [<80151b70>] (vfs_ioctl+0x38/0x4c)
[<80151b70>] (vfs_ioctl+0x38/0x4c) from [<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4)
[<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4) from [<801527c8>] (SyS_ioctl+0x60/0x8c)
[<801527c8>] (SyS_ioctl+0x60/0x8c) from [<8000dde0>] (ret_fast_syscall+0x0/0x48)
please wait |
please wait |
please wait \
BUG: spinlock lockup suspected on CPU#1, lttng-sessiond/926
lock: 0xbd0a832c, .magic: dead4ead, .owner: lttng-sessiond/926, .owner_cpu: 1
CPU: 1 PID: 926 Comm: lttng-sessiond Tainted: G C 3.10.38-ltsi-WR6.0.0.0_standard #1
[<800170e0>] (unwind_backtrace+0x0/0xec) from [<800125ec>] (show_stack+0x20/0x24)
[<800125ec>] (show_stack+0x20/0x24) from [<806a698c>] (dump_stack+0x20/0x28)
[<806a698c>] (dump_stack+0x20/0x28) from [<806a70b0>] (spin_dump+0x80/0x94)
[<806a70b0>] (spin_dump+0x80/0x94) from [<803508c0>] (do_raw_spin_lock+0x124/0x174)
[<803508c0>] (do_raw_spin_lock+0x124/0x174) from [<806abff0>] (_raw_spin_lock+0x50/0x58)
[<806abff0>] (_raw_spin_lock+0x50/0x58) from [<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump])
[<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump]) from [<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer])
[<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer]) from [<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer])
[<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer]) from [<80151b70>] (vfs_ioctl+0x38/0x4c)
[<80151b70>] (vfs_ioctl+0x38/0x4c) from [<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4)
[<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4) from [<801527c8>] (SyS_ioctl+0x60/0x8c)
[<801527c8>] (SyS_ioctl+0x60/0x8c) from [<8000dde0>] (ret_fast_syscall+0x0/0x48)
Message from syslogd@localhost at Sep 19 02:14:47 ...
kernel:BUG: spinlock lockup suspected on CPU#1, lttng-sessiond/926
Message from syslogd@localhost at Sep 19 02:14:47 ...
kernel: lock: 0xbd0a832c, .magic: dead4ead, .owner: lttng-sessiond/926, .owner_cpu: 1
INFO: rcu_preempt self-detected stall on CPU { 1} (t=2601 jiffies g=10429 c=10428 q=32332)
CPU: 1 PID: 926 Comm: lttng-sessiond Tainted: G C 3.10.38-ltsi-WR6.0.0.0_standard #1
INFO: rcu_preempt detected stalls on CPUs/tasks: { 1} (detected by 0, t=2602 jiffies, g=10429, c=10428, q=32332)
Task dump for CPU 1:
lttng-sessiond R running 0 926 1 0x00000006
[<800170e0>] (unwind_backtrace+0x0/0xec) from [<800125ec>] (show_stack+0x20/0x24)
[<800125ec>] (show_stack+0x20/0x24) from [<806a698c>] (dump_stack+0x20/0x28)
[<806a698c>] (dump_stack+0x20/0x28) from [<800bb550>] (rcu_check_callbacks+0x270/0x8e4)
[<800bb550>] (rcu_check_callbacks+0x270/0x8e4) from [<8003bf6c>] (update_process_times+0x4c/0x78)
[<8003bf6c>] (update_process_times+0x4c/0x78) from [<80081d88>] (tick_sched_handle.isra.9+0x64/0x70)
[<80081d88>] (tick_sched_handle.isra.9+0x64/0x70) from [<80081de8>] (tick_sched_timer+0x54/0x84)
[<80081de8>] (tick_sched_timer+0x54/0x84) from [<80057774>] (__run_hrtimer+0x1b8/0x4e4)
[<80057774>] (__run_hrtimer+0x1b8/0x4e4) from [<80058780>] (hrtimer_interrupt+0x144/0x29c)
[<80058780>] (hrtimer_interrupt+0x144/0x29c) from [<800150b4>] (twd_handler+0x44/0x58)
[<800150b4>] (twd_handler+0x44/0x58) from [<800b4ed0>] (handle_percpu_devid_irq+0x104/0x330)
[<800b4ed0>] (handle_percpu_devid_irq+0x104/0x330) from [<800b0fa0>] (generic_handle_irq+0x30/0x40)
[<800b0fa0>] (generic_handle_irq+0x30/0x40) from [<8000ee24>] (handle_IRQ+0x78/0xa0)
[<8000ee24>] (handle_IRQ+0x78/0xa0) from [<80008764>] (gic_handle_irq+0x4c/0x70)
[<80008764>] (gic_handle_irq+0x4c/0x70) from [<806acec4>] (__irq_svc+0x44/0x78)
Exception stack(0xb7fb7a68 to 0xb7fb7ab0)
7a60: fffffff7 00000000 0000005f 0000005e 27b28000 00000000
7a80: 27b28000 00000000 bd0a832c b7fb6030 80a42238 b7fb7adc 8000dde0 b7fb7ab0
7aa0: 80016d20 803508e8 20000013 ffffffff
[<806acec4>] (__irq_svc+0x44/0x78) from [<803508e8>] (do_raw_spin_lock+0x14c/0x174)
[<803508e8>] (do_raw_spin_lock+0x14c/0x174) from [<806abff0>] (_raw_spin_lock+0x50/0x58)
[<806abff0>] (_raw_spin_lock+0x50/0x58) from [<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump])
[<7f01d560>] (lttng_statedump_start+0x1f8/0x10e8 [lttng_statedump]) from [<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer])
[<7f02587c>] (lttng_session_enable+0x4c0/0x540 [lttng_tracer]) from [<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer])
[<7f02614c>] (lttng_session_ioctl+0x220/0x2b4 [lttng_tracer]) from [<80151b70>] (vfs_ioctl+0x38/0x4c)
[<80151b70>] (vfs_ioctl+0x38/0x4c) from [<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4)
[<801526bc>] (do_vfs_ioctl+0x4f8/0x5a4) from [<801527c8>] (SyS_ioctl+0x60/0x8c)
[<801527c8>] (SyS_ioctl+0x60/0x8c) from [<8000dde0>] (ret_fast_syscall+0x0/0x48)
BUG: soft lockup - CPU#1 stuck for 22s! [lttng-sessiond:926]
lttng_ring_buffer_client_mmap_discard(C) lttng_ring_buffer_client_overwrite(C) lttng_ring_buffer_metadata_client(C) lttng_ring_buffer_metadata_mmap_client(C) lttng_probe_regmap(C) lttng_probe_rpm(C) lttng_probe_power(C) lttng_probe_scsi(C) lttng_probe_jbd2(C) lttng_probe_sched(C) lttng_probe_block(C) lttng_probe_printk(C) lttng_probe_writeback(C) lttng_probe_rcu(C) lttng_probe_btrfs(C) lttng_probe_vmscan(C) lttng_probe_napi(C) lttng_probe_ext3(C) lttng_types(C) lttng_probe_sock(C) lttng_probe_jbd(C) lttng_probe_compaction(C) lttng_probe_net(C) lttng_probe_sunrpc(C) lttng_probe_ext4(C) lttng_probe_statedump(C) lttng_probe_udp(C) lttng_probe_skb(C) lttng_probe_kmem(C) lttng_probe_signal(C) lttng_probe_module(C) lttng_probe_asoc(C) lttng_probe_random(C) lttng_probe_workqueue(C) lttng_probe_timer(C) lttng_probe_gpio(C) lttng_probe_irq(C) lttng_tracer(C) lttng_statedump(C) lttng_ftrace(C) lttng_kprobes(C) lttng_lib_ring_buffer(C) lttng_kretprobes(C)
irq event stamp: 24445
hardirqs last enabled at (24445): [<806ac32c>] _raw_spin_unlock_irqrestore+0x4c/0x78
hardirqs last disabled at (24444): [<806ac138>] _raw_spin_lock_irqsave+0x2c/0x68
softirqs last enabled at (23708): [<80032200>] __do_softirq+0x2cc/0x478
softirqs last disabled at (23045): [<80032478>] do_softirq+0x58/0x7c
CPU: 1 PID: 926 Comm: lttng-sessiond Tainted: G C 3.10.38-ltsi-WR6.0.0.0_standard #1
task: b9154c00 ti: b7fb6000 task.ti: b7fb6000
PC is at do_raw_spin_lock+0x14c/0x174
LR is at unwind_frame+0xac/0x46c
pc : [<803508e8>] lr : [<80016d20>] psr: 20000013
sp : b7fb7ab0 ip : 8000dde0 fp : b7fb7adc
r10: 80a42238 r9 : b7fb6030 r8 : bd0a832c
r7 : 00000000 r6 : 27b28000 r5 : 00000000 r4 : 27b28000
r3 : 0000005e r2 : 0000005f r1 : 00000000 r0 : fffffff7
Flags: nzCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
Control: 18c5387d Table: 37d2804a DAC: 00000015
CPU: 1 PID: 926 Comm: lttng-sessiond Tainted: G C 3.10.38-ltsi-WR6.0.0.0_standard #1
[<800170e0>] (unwind_backtrace+0x0/0xec) from [<800125ec>] (show_stack+0x20/0x24)
[<800125ec>] (show_stack+0x20/0x24) from [<806a698c>] (dump_stack+0x20/0x28)
[<806a698c>] (dump_stack+0x20/0x28) from [<8000f504>] (show_regs+0x2c/0x34)
[<8000f504>] (show_regs+0x2c/0x34) from [<800b0c58>] (watchdog_timer_fn+0x130/0x184)
[<800b0c58>] (watchdog_timer_fn+0x130/0x184) from [<80057774>] (__run_hrtimer+0x1b8/0x4e4)
[<80057774>] (__run_hrtimer+0x1b8/0x4e4) from [<80058780>] (hrtimer_interrupt+0x144/0x29c)
[<80058780>] (hrtimer_interrupt+0x144/0x29c) from [<800150b4>] (twd_handler+0x44/0x58)
[<800150b4>] (twd_handler+0x44/0x58) from [<800b4ed0>] (handle_percpu_devid_irq+0x104/0x330)
[<800b4ed0>] (handle_percpu_devid_irq+0x104/0x330) from [<800b0fa0>] (generic_handle_irq+0x30/0x40)
[<800b0fa0>] (generic_handle_irq+0x30/0x40) from [<8000ee24>] (handle_IRQ+0x78/0xa0)
[<8000ee24>] (handle_IRQ+0x78/0xa0) from [<80008764>] (gic_handle_irq+0x4c/0x70)
[<80008764>] (gic_handle_irq+0x4c/0x70) from [<806acec4>] (__irq_svc+0x44/0x78)
Exception stack(0xb7fb7a68 to 0xb7fb7ab0)
7a60: fffffff7 00000000 0000005f 0000005e 27b28000 00000000
7a80: 27b28000 00000000 bd0a832c b7fb6030 80a42238 b7fb7adc 8000dde0 b7fb7ab0
7aa0: 80016d20 803508e8 20000013 ffffffff
1). Build project
${GIT}/wrlinux-x/wrlinux/configure --enable-board=xilinx-zynq --enable-kernel=standard --enable-rootfs=glibc-std --enable-test=yes --with-layer=${wr-testing}/kts-test,${wr-testing}/bts,${wr-testing}/ltp,${wr-testing}/bts-new --with-template=feature/kts-basic,feature/kts-extended,feature/kts-standard,feature/bts --enable-parallel-pkgbuilds=16 --enable-jobs=16 --enable-reconfig && make fs
2). Boot target from SD card
# cat /proc/cmdline
console=ttyPS0,115200 earlyprintk root=/dev/mmcblk0p2 ro rootwait
3). Run lttng2
root@localhost:/opt/wr-test# ./main_test.sh -u xxx -s lttng2
