Fixed
Created: Nov 18, 2014
Updated: Dec 3, 2018
Resolved Date: Nov 24, 2014
Previous ID: LIN5-19753
Found In Version: 6.0.0.13
Fix Version: 6.0.0.15
Severity: Standard
Applicable for: Wind River Linux 6
Component/s: Kernel
root@localhost:/opt/wr-test# ./main_test.sh -s lttng
/opt/wr-test/lib/lib_env.sh: line 21: rdate: command not found
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
The test case list :
lttng
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Start kts Case lttng at Mon Apr 5 18:43:21 UTC 2004 with duration 120 s
LTT : ltt-kprobes init
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 1767 events written in channel rcu (cpu 0, index 0)
LTT: 120 events written in channel pm (cpu 0, index 0)
LTT: 543 events written in channel mm (cpu 0, index 0)
LTT: 30 events written in channel net (cpu 0, index 0)
LTT: 388 events written in channel fs (cpu 0, index 0)
LTT: 8078 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1053 events written in channel vm_state (cpu 0, index 0)
LTT: 315 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 515 events written in channel rcu (cpu 0, index 0)
LTT: 137 events written in channel mm (cpu 0, index 0)
LTT: 13 events written in channel net (cpu 0, index 0)
LTT: 166 events written in channel fs (cpu 0, index 0)
LTT: 2056 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1044 events written in channel vm_state (cpu 0, index 0)
LTT: 315 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 309 events written in channel rcu (cpu 0, index 0)
LTT: 122 events written in channel mm (cpu 0, index 0)
LTT: 9 events written in channel net (cpu 0, index 0)
LTT: 64 events written in channel fs (cpu 0, index 0)
LTT: 1628 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1055 events written in channel vm_state (cpu 0, index 0)
LTT: 313 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
please wait -
======================================================
[ INFO: possible circular locking dependency detected ]
3.4.88-WR5.0.1.0_standard #2 Not tainted
-------------------------------------------------------
rmmod/15693 is trying to acquire lock:
(module_mutex){+.+.+.}, at: [<c109660c>] module_get_iter_markers+0x1c/0xa0
but task is already holding lock:
((module_notify_list).rwsem){.+.+.+}, at: [<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 ((module_notify_list).rwsem){.+.+.+}:
[<c108a35e>] lock_acquire+0x7e/0x120
[<c14de70e>] down_read+0x4e/0x60
[<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c1092472>] module_unload_free+0xa2/0xc0
[<c1094c18>] sys_init_module+0x958/0x1c40
[<c14e0b65>] syscall_call+0x7/0xb
-> #0 (module_mutex){+.+.+.}:
[<c10897b8>] __lock_acquire+0x1138/0x1730
[<c108a35e>] lock_acquire+0x7e/0x120
[<c14dd5c6>] mutex_lock_nested+0x66/0x2f0
[<c109660c>] module_get_iter_markers+0x1c/0xa0
[<c10ba928>] marker_get_iter+0x18/0x50
[<c10ba971>] marker_iter_next+0x11/0x20
[<c128a710>] cleanup_control_dir+0x90/0x130
[<c128a7e2>] module_notify+0x32/0xa0
[<c14e45e5>] notifier_call_chain+0x45/0x60
[<c10599f3>] __blocking_notifier_call_chain+0x43/0x70
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c10940a8>] sys_delete_module+0x138/0x220
[<c14e0b65>] syscall_call+0x7/0xb
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock((module_notify_list).rwsem);
lock(module_mutex);
lock((module_notify_list).rwsem);
lock(module_mutex);
*** DEADLOCK ***
1 lock held by rmmod/15693:
#0: ((module_notify_list).rwsem){.+.+.+}, at: [<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
stack backtrace:
Pid: 15693, comm: rmmod Not tainted 3.4.88-WR5.0.1.0_standard #2
Call Trace:
[<c14d7b8e>] print_circular_bug+0x1b4/0x1be
[<c10897b8>] __lock_acquire+0x1138/0x1730
[<c108a35e>] lock_acquire+0x7e/0x120
[<c109660c>] ? module_get_iter_markers+0x1c/0xa0
[<c14dd5c6>] mutex_lock_nested+0x66/0x2f0
[<c109660c>] ? module_get_iter_markers+0x1c/0xa0
[<c11426b6>] ? dput+0x1a6/0x230
[<c14e0852>] ? _raw_spin_unlock+0x22/0x30
[<c109660c>] module_get_iter_markers+0x1c/0xa0
[<c10ba928>] marker_get_iter+0x18/0x50
[<c10ba971>] marker_iter_next+0x11/0x20
[<c128a710>] cleanup_control_dir+0x90/0x130
[<c128a7e2>] module_notify+0x32/0xa0
[<c14e45e5>] notifier_call_chain+0x45/0x60
[<c10599f3>] __blocking_notifier_call_chain+0x43/0x70
[<c1087abb>] ? trace_hardirqs_on+0xb/0x10
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c10940a8>] sys_delete_module+0x138/0x220
[<c11116f6>] ? vm_munmap+0x46/0x60
[<c14e0b98>] ? restore_all+0xf/0xf
[<c14e0b65>] syscall_call+0x7/0xb
LTT : ltt-kprobes exit
LTT : State dump exit
lakemore: control module (built Jul 21 2014 - 13:17:42)
lakemore: registering probe lakemore_config
lakemore: init done
lakemore: unloading control module
lakemore: finished cleanup
[lttng] results:[ FAILED ]
==========================================
********Detail logs for lttng**********
lttng.cfg readable!
lttng.pkg readable!
lttng-control-0.89-r2.i586
Found the lttng-control package installed.
lttng-viewer-0.12.38-r3.i586
Found the lttng-viewer package installed.
lttng-ust-0.16-r2.i586
Found the lttng-ust package installed.
############################################################
Check LTTNG kernel configs.
############################################################
############################################################
Start to test Lttng
############################################################
PASS to insmod the kernel module ltt-statedump
ltt-userspace-event
trap-trace
syscall-trace
block-trace
fs-trace
net-trace
jbd2-trace
kernel-trace
lockdep-trace
mm-trace
pm-trace
rcu-trace
ipc-trace
net-extended-trace
ltt-filter
ltt-kprobes
############################################################
# 1st, check whethere and where the debugfs mounted #
############################################################
mount debugfs on /mnt/debugfs
############################################################
# 2nd, start to test Lttng feature with ltt-statedump
ltt-userspace-event
trap-trace
syscall-trace
block-trace
fs-trace
net-trace
jbd2-trace
kernel-trace
lockdep-trace
mm-trace
pm-trace
rcu-trace
ipc-trace
net-extended-trace
ltt-filter
ltt-kprobes and lttv package #
############################################################
Connecting /sys/kernel/debug/ltt/markers/kprobe_state/kprobe_table
Connecting /sys/kernel/debug/ltt/markers/ipc/call
Connecting /sys/kernel/debug/ltt/markers/ipc/shm_create
Connecting /sys/kernel/debug/ltt/markers/ipc/sem_create
Connecting /sys/kernel/debug/ltt/markers/ipc/msg_create
Connecting /sys/kernel/debug/ltt/markers/rcu/tree_call_rcu_bh
Connecting /sys/kernel/debug/ltt/markers/rcu/tree_call_rcu
Connecting /sys/kernel/debug/ltt/markers/rcu/tree_callback
Connecting /sys/kernel/debug/ltt/markers/pm/suspend_exit
Connecting /sys/kernel/debug/ltt/markers/pm/suspend_entry
Connecting /sys/kernel/debug/ltt/markers/pm/idle_exit
Connecting /sys/kernel/debug/ltt/markers/pm/idle_entry
Connecting /sys/kernel/debug/ltt/markers/mm/remove_from_page_cache
Connecting /sys/kernel/debug/ltt/markers/mm/add_to_page_cache
Connecting /sys/kernel/debug/ltt/markers/mm/page_alloc
Connecting /sys/kernel/debug/ltt/markers/mm/page_free
Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_alloc
Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_free
Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_end
Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_start
Connecting /sys/kernel/debug/ltt/markers/jbd2/end_commit
Connecting /sys/kernel/debug/ltt/markers/jbd2/start_commit
Connecting /sys/kernel/debug/ltt/markers/jbd2/checkpoint
Connecting /sys/kernel/debug/ltt/markers/net/napi_complete
Connecting /sys/kernel/debug/ltt/markers/net/napi_poll
Connecting /sys/kernel/debug/ltt/markers/net/napi_schedule
Connecting /sys/kernel/debug/ltt/markers/net/udpv4_rcv
Connecting /sys/kernel/debug/ltt/markers/net/tcpv4_rcv
Connecting /sys/kernel/debug/ltt/markers/net/socket_call
Connecting /sys/kernel/debug/ltt/markers/net/socket_shutdown
Connecting /sys/kernel/debug/ltt/markers/net/socket_getsockopt
Connecting /sys/kernel/debug/ltt/markers/net/socket_setsockopt
Connecting /sys/kernel/debug/ltt/markers/net/socket_recvmsg
Connecting /sys/kernel/debug/ltt/markers/net/socket_sendmsg
Connecting /sys/kernel/debug/ltt/markers/net/socket_socketpair
Connecting /sys/kernel/debug/ltt/markers/net/socket_getpeername
Connecting /sys/kernel/debug/ltt/markers/net/socket_getsockname
Connecting /sys/kernel/debug/ltt/markers/net/socket_accept
Connecting /sys/kernel/debug/ltt/markers/net/socket_listen
Connecting /sys/kernel/debug/ltt/markers/net/socket_connect
Connecting /sys/kernel/debug/ltt/markers/net/socket_bind
Connecting /sys/kernel/debug/ltt/markers/net/socket_create
Connecting /sys/kernel/debug/ltt/markers/net/dev_receive
Connecting /sys/kernel/debug/ltt/markers/net/dev_xmit
Connecting /sys/kernel/debug/ltt/markers/fs/dup
Connecting /sys/kernel/debug/ltt/markers/fs/pollfd
Connecting /sys/kernel/debug/ltt/markers/fs/select
Connecting /sys/kernel/debug/ltt/markers/fs/writev
Connecting /sys/kernel/debug/ltt/markers/fs/readv
Connecting /sys/kernel/debug/ltt/markers/fs/pwrite64
Connecting /sys/kernel/debug/ltt/markers/fs/pread64
Connecting /sys/kernel/debug/ltt/markers/fs/write
Connecting /sys/kernel/debug/ltt/markers/fs/read
Connecting /sys/kernel/debug/ltt/markers/fs/llseek
Connecting /sys/kernel/debug/ltt/markers/fs/lseek
Connecting /sys/kernel/debug/ltt/markers/fs/close
Connecting /sys/kernel/debug/ltt/markers/fs/open
Connecting /sys/kernel/debug/ltt/markers/fs/ioctl
Connecting /sys/kernel/debug/ltt/markers/fs/exec
Connecting /sys/kernel/debug/ltt/markers/fs/buffer_wait_end
Connecting /sys/kernel/debug/ltt/markers/fs/buffer_wait_start
Connecting /sys/kernel/debug/ltt/markers/block/rq_remap
Connecting /sys/kernel/debug/ltt/markers/block/bio_remap
Connecting /sys/kernel/debug/ltt/markers/block/split
Connecting /sys/kernel/debug/ltt/markers/block/unplug
Connecting /sys/kernel/debug/ltt/markers/block/plug
Connecting /sys/kernel/debug/ltt/markers/block/sleeprq
Connecting /sys/kernel/debug/ltt/markers/block/sleeprq_bio
Connecting /sys/kernel/debug/ltt/markers/block/getrq
Connecting /sys/kernel/debug/ltt/markers/block/getrq_bio
Connecting /sys/kernel/debug/ltt/markers/block/bio_queue
Connecting /sys/kernel/debug/ltt/markers/block/bio_frontmerge
Connecting /sys/kernel/debug/ltt/markers/block/bio_backmerge
Connecting /sys/kernel/debug/ltt/markers/block/bio_complete
Connecting /sys/kernel/debug/ltt/markers/block/bio_bounce
Connecting /sys/kernel/debug/ltt/markers/block/rq_complete_fs
Connecting /sys/kernel/debug/ltt/markers/block/rq_complete_pc
Connecting /sys/kernel/debug/ltt/markers/block/rq_requeue_fs
Connecting /sys/kernel/debug/ltt/markers/block/rq_requeue_pc
Connecting /sys/kernel/debug/ltt/markers/block/rq_issue_fs
Connecting /sys/kernel/debug/ltt/markers/block/rq_issue_pc
Connecting /sys/kernel/debug/ltt/markers/block/rq_insert_fs
Connecting /sys/kernel/debug/ltt/markers/block/rq_insert_pc
Connecting /sys/kernel/debug/ltt/markers/block/rq_abort_fs
Connecting /sys/kernel/debug/ltt/markers/block/rq_abort_pc
Connecting /sys/kernel/debug/ltt/markers/kernel/kprobe
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_get_user_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_get_user_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_nosem_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_nosem_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/page_fault_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/crash_kexec
Connecting /sys/kernel/debug/ltt/markers/kernel/kernel_kexec
Connecting /sys/kernel/debug/ltt/markers/kernel/panic
Connecting /sys/kernel/debug/ltt/markers/kernel/module_load
Connecting /sys/kernel/debug/ltt/markers/kernel/module_free
Connecting /sys/kernel/debug/ltt/markers/kernel/vprintk
Connecting /sys/kernel/debug/ltt/markers/kernel/printk
Connecting /sys/kernel/debug/ltt/markers/kernel/timer_timeout
Connecting /sys/kernel/debug/ltt/markers/kernel/timer_update_time
Connecting /sys/kernel/debug/ltt/markers/kernel/timer_set
Connecting /sys/kernel/debug/ltt/markers/kernel/timer_itimer_set
Connecting /sys/kernel/debug/ltt/markers/kernel/timer_itimer_expired
Connecting /sys/kernel/debug/ltt/markers/kernel/kthread_create
Connecting /sys/kernel/debug/ltt/markers/kernel/process_fork
Connecting /sys/kernel/debug/ltt/markers/kernel/process_wait
Connecting /sys/kernel/debug/ltt/markers/kernel/process_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/process_free
Connecting /sys/kernel/debug/ltt/markers/kernel/send_signal
Connecting /sys/kernel/debug/ltt/markers/kernel/sched_migrate_task
Connecting /sys/kernel/debug/ltt/markers/kernel/sched_schedule
Connecting /sys/kernel/debug/ltt/markers/kernel/sched_wakeup_new_task
Connecting /sys/kernel/debug/ltt/markers/kernel/sched_try_wakeup
Connecting /sys/kernel/debug/ltt/markers/kernel/sched_wait_task
Connecting /sys/kernel/debug/ltt/markers/kernel/kthread_stop_ret
Connecting /sys/kernel/debug/ltt/markers/kernel/kthread_stop
Connecting /sys/kernel/debug/ltt/markers/kernel/tasklet_high_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/tasklet_high_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/tasklet_low_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/tasklet_low_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/softirq_raise
Connecting /sys/kernel/debug/ltt/markers/kernel/softirq_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/softirq_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/irq_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/irq_next_handler
Connecting /sys/kernel/debug/ltt/markers/kernel/irq_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/syscall_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/syscall_entry
Connecting /sys/kernel/debug/ltt/markers/kernel/trap_exit
Connecting /sys/kernel/debug/ltt/markers/kernel/trap_entry
Connecting /sys/kernel/debug/ltt/markers/userspace/event
Connecting /sys/kernel/debug/ltt/markers/netif_state/insert_ifa_ipv6
Connecting /sys/kernel/debug/ltt/markers/netif_state/del_ifa_ipv4
Connecting /sys/kernel/debug/ltt/markers/netif_state/insert_ifa_ipv4
Connecting /sys/kernel/debug/ltt/markers/netif_state/network_ip_interface
Connecting /sys/kernel/debug/ltt/markers/netif_state/network_ipv4_interface
Connecting /sys/kernel/debug/ltt/markers/global_state/statedump_end
Connecting /sys/kernel/debug/ltt/markers/enum_tables/vmx_kvm_exit
Connecting /sys/kernel/debug/ltt/markers/vm_state/vm_map
Connecting /sys/kernel/debug/ltt/markers/fd_state/file_descriptor
Connecting /sys/kernel/debug/ltt/markers/task_state/process_state
Connecting /sys/kernel/debug/ltt/markers/module_state/list_module
Connecting /sys/kernel/debug/ltt/markers/softirq_state/softirq_vec
Connecting /sys/kernel/debug/ltt/markers/irq_state/interrupt
Connecting /sys/kernel/debug/ltt/markers/irq_state/idt_table
Connecting /sys/kernel/debug/ltt/markers/syscall_state/sys_call_table
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace1
lttctl: Creating trace
lttctl: Forking lttd
lttctl: Starting trace
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace1
lttctl: Pausing trace
lttctl: Destroying trace
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace2
lttctl: Creating trace
lttctl: Forking lttd
lttctl: Starting trace
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace2
lttctl: Pausing trace
lttctl: Forking lttd
lttctl: Destroying trace
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace3
lttctl: Creating trace
lttctl: Forking lttd
lttctl: Starting trace
Linux Trace Toolkit Trace Control 0.89-05122011
Controlling trace : trace3
lttctl: Pausing trace
lttctl: Forking lttd
lttctl: Destroying trace
Dumping tracing results, please wait for several seconds...
Disconnecting /sys/kernel/debug/ltt/markers/kprobe_state/kprobe_table
Disconnecting /sys/kernel/debug/ltt/markers/ipc/call
Disconnecting /sys/kernel/debug/ltt/markers/ipc/shm_create
Disconnecting /sys/kernel/debug/ltt/markers/ipc/sem_create
Disconnecting /sys/kernel/debug/ltt/markers/ipc/msg_create
Disconnecting /sys/kernel/debug/ltt/markers/rcu/tree_call_rcu_bh
Disconnecting /sys/kernel/debug/ltt/markers/rcu/tree_call_rcu
Disconnecting /sys/kernel/debug/ltt/markers/rcu/tree_callback
Disconnecting /sys/kernel/debug/ltt/markers/pm/suspend_exit
Disconnecting /sys/kernel/debug/ltt/markers/pm/suspend_entry
Disconnecting /sys/kernel/debug/ltt/markers/pm/idle_exit
Disconnecting /sys/kernel/debug/ltt/markers/pm/idle_entry
Disconnecting /sys/kernel/debug/ltt/markers/mm/remove_from_page_cache
Disconnecting /sys/kernel/debug/ltt/markers/mm/add_to_page_cache
Disconnecting /sys/kernel/debug/ltt/markers/mm/page_alloc
Disconnecting /sys/kernel/debug/ltt/markers/mm/page_free
Disconnecting /sys/kernel/debug/ltt/markers/mm/huge_page_alloc
Disconnecting /sys/kernel/debug/ltt/markers/mm/huge_page_free
Disconnecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_end
Disconnecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_start
Disconnecting /sys/kernel/debug/ltt/markers/jbd2/end_commit
Disconnecting /sys/kernel/debug/ltt/markers/jbd2/start_commit
Disconnecting /sys/kernel/debug/ltt/markers/jbd2/checkpoint
Disconnecting /sys/kernel/debug/ltt/markers/net/napi_complete
Disconnecting /sys/kernel/debug/ltt/markers/net/napi_poll
Disconnecting /sys/kernel/debug/ltt/markers/net/napi_schedule
Disconnecting /sys/kernel/debug/ltt/markers/net/udpv4_rcv
Disconnecting /sys/kernel/debug/ltt/markers/net/tcpv4_rcv
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_call
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_shutdown
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_getsockopt
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_setsockopt
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_recvmsg
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_sendmsg
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_socketpair
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_getpeername
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_getsockname
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_accept
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_listen
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_connect
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_bind
Disconnecting /sys/kernel/debug/ltt/markers/net/socket_create
Disconnecting /sys/kernel/debug/ltt/markers/net/dev_receive
Disconnecting /sys/kernel/debug/ltt/markers/net/dev_xmit
Disconnecting /sys/kernel/debug/ltt/markers/fs/dup
Disconnecting /sys/kernel/debug/ltt/markers/fs/pollfd
Disconnecting /sys/kernel/debug/ltt/markers/fs/select
Disconnecting /sys/kernel/debug/ltt/markers/fs/writev
Disconnecting /sys/kernel/debug/ltt/markers/fs/readv
Disconnecting /sys/kernel/debug/ltt/markers/fs/pwrite64
Disconnecting /sys/kernel/debug/ltt/markers/fs/pread64
Disconnecting /sys/kernel/debug/ltt/markers/fs/write
Disconnecting /sys/kernel/debug/ltt/markers/fs/read
Disconnecting /sys/kernel/debug/ltt/markers/fs/llseek
Disconnecting /sys/kernel/debug/ltt/markers/fs/lseek
Disconnecting /sys/kernel/debug/ltt/markers/fs/close
Disconnecting /sys/kernel/debug/ltt/markers/fs/open
Disconnecting /sys/kernel/debug/ltt/markers/fs/ioctl
Disconnecting /sys/kernel/debug/ltt/markers/fs/exec
Disconnecting /sys/kernel/debug/ltt/markers/fs/buffer_wait_end
Disconnecting /sys/kernel/debug/ltt/markers/fs/buffer_wait_start
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_remap
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_remap
Disconnecting /sys/kernel/debug/ltt/markers/block/split
Disconnecting /sys/kernel/debug/ltt/markers/block/unplug
Disconnecting /sys/kernel/debug/ltt/markers/block/plug
Disconnecting /sys/kernel/debug/ltt/markers/block/sleeprq
Disconnecting /sys/kernel/debug/ltt/markers/block/sleeprq_bio
Disconnecting /sys/kernel/debug/ltt/markers/block/getrq
Disconnecting /sys/kernel/debug/ltt/markers/block/getrq_bio
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_queue
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_frontmerge
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_backmerge
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_complete
Disconnecting /sys/kernel/debug/ltt/markers/block/bio_bounce
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_complete_fs
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_complete_pc
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_requeue_fs
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_requeue_pc
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_issue_fs
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_issue_pc
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_insert_fs
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_insert_pc
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_abort_fs
Disconnecting /sys/kernel/debug/ltt/markers/block/rq_abort_pc
Disconnecting /sys/kernel/debug/ltt/markers/kernel/kprobe
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_get_user_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_get_user_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_nosem_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_nosem_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/page_fault_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/crash_kexec
Disconnecting /sys/kernel/debug/ltt/markers/kernel/kernel_kexec
Disconnecting /sys/kernel/debug/ltt/markers/kernel/panic
Disconnecting /sys/kernel/debug/ltt/markers/kernel/module_load
Disconnecting /sys/kernel/debug/ltt/markers/kernel/module_free
Disconnecting /sys/kernel/debug/ltt/markers/kernel/vprintk
Disconnecting /sys/kernel/debug/ltt/markers/kernel/printk
Disconnecting /sys/kernel/debug/ltt/markers/kernel/timer_timeout
Disconnecting /sys/kernel/debug/ltt/markers/kernel/timer_update_time
Disconnecting /sys/kernel/debug/ltt/markers/kernel/timer_set
Disconnecting /sys/kernel/debug/ltt/markers/kernel/timer_itimer_set
Disconnecting /sys/kernel/debug/ltt/markers/kernel/timer_itimer_expired
Disconnecting /sys/kernel/debug/ltt/markers/kernel/kthread_create
Disconnecting /sys/kernel/debug/ltt/markers/kernel/process_fork
Disconnecting /sys/kernel/debug/ltt/markers/kernel/process_wait
Disconnecting /sys/kernel/debug/ltt/markers/kernel/process_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/process_free
Disconnecting /sys/kernel/debug/ltt/markers/kernel/send_signal
Disconnecting /sys/kernel/debug/ltt/markers/kernel/sched_migrate_task
Disconnecting /sys/kernel/debug/ltt/markers/kernel/sched_schedule
Disconnecting /sys/kernel/debug/ltt/markers/kernel/sched_wakeup_new_task
Disconnecting /sys/kernel/debug/ltt/markers/kernel/sched_try_wakeup
Disconnecting /sys/kernel/debug/ltt/markers/kernel/sched_wait_task
Disconnecting /sys/kernel/debug/ltt/markers/kernel/kthread_stop_ret
Disconnecting /sys/kernel/debug/ltt/markers/kernel/kthread_stop
Disconnecting /sys/kernel/debug/ltt/markers/kernel/tasklet_high_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/tasklet_high_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/tasklet_low_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/tasklet_low_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/softirq_raise
Disconnecting /sys/kernel/debug/ltt/markers/kernel/softirq_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/softirq_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/irq_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/irq_next_handler
Disconnecting /sys/kernel/debug/ltt/markers/kernel/irq_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/syscall_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/syscall_entry
Disconnecting /sys/kernel/debug/ltt/markers/kernel/trap_exit
Disconnecting /sys/kernel/debug/ltt/markers/kernel/trap_entry
Disconnecting /sys/kernel/debug/ltt/markers/userspace/event
Disconnecting /sys/kernel/debug/ltt/markers/netif_state/insert_ifa_ipv6
Disconnecting /sys/kernel/debug/ltt/markers/netif_state/del_ifa_ipv4
Disconnecting /sys/kernel/debug/ltt/markers/netif_state/insert_ifa_ipv4
Disconnecting /sys/kernel/debug/ltt/markers/netif_state/network_ip_interface
Disconnecting /sys/kernel/debug/ltt/markers/netif_state/network_ipv4_interface
Disconnecting /sys/kernel/debug/ltt/markers/global_state/statedump_end
Disconnecting /sys/kernel/debug/ltt/markers/enum_tables/vmx_kvm_exit
Disconnecting /sys/kernel/debug/ltt/markers/vm_state/vm_map
Disconnecting /sys/kernel/debug/ltt/markers/fd_state/file_descriptor
Disconnecting /sys/kernel/debug/ltt/markers/task_state/process_state
Disconnecting /sys/kernel/debug/ltt/markers/module_state/list_module
Disconnecting /sys/kernel/debug/ltt/markers/softirq_state/softirq_vec
Disconnecting /sys/kernel/debug/ltt/markers/irq_state/interrupt
Disconnecting /sys/kernel/debug/ltt/markers/irq_state/idt_table
Disconnecting /sys/kernel/debug/ltt/markers/syscall_state/sys_call_table
############################################################
The kernel feature Lttng is successful!
############################################################
PASS lttng test
Tests Passed : 1
Tests Failed : 0
Tests Skiped : 0
Tests Manual : 0
Total Tested : 1
Call Trace:
There was Call Trace/BUG information during the testing
LTT : State dump init
LTT : ltt-kprobes init
LTT state dump begin
LTT state dump thread start
LTT state dump end
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 1767 events written in channel rcu (cpu 0, index 0)
LTT: 120 events written in channel pm (cpu 0, index 0)
LTT: 543 events written in channel mm (cpu 0, index 0)
LTT: 30 events written in channel net (cpu 0, index 0)
LTT: 388 events written in channel fs (cpu 0, index 0)
LTT: 8078 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1053 events written in channel vm_state (cpu 0, index 0)
LTT: 315 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
LTT state dump begin
LTT state dump thread start
LTT state dump end
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 515 events written in channel rcu (cpu 0, index 0)
LTT: 137 events written in channel mm (cpu 0, index 0)
LTT: 13 events written in channel net (cpu 0, index 0)
LTT: 166 events written in channel fs (cpu 0, index 0)
LTT: 2056 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1044 events written in channel vm_state (cpu 0, index 0)
LTT: 315 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
LTT state dump begin
LTT state dump thread start
LTT state dump end
LTT: 298 events written in channel metadata (cpu 0, index 0)
LTT: 309 events written in channel rcu (cpu 0, index 0)
LTT: 122 events written in channel mm (cpu 0, index 0)
LTT: 9 events written in channel net (cpu 0, index 0)
LTT: 64 events written in channel fs (cpu 0, index 0)
LTT: 1628 events written in channel kernel (cpu 0, index 0)
LTT: 2 events written in channel netif_state (cpu 0, index 0)
LTT: 1 events written in channel global_state (cpu 0, index 0)
LTT: 35 events written in channel enum_tables (cpu 0, index 0)
LTT: 1055 events written in channel vm_state (cpu 0, index 0)
LTT: 313 events written in channel fd_state (cpu 0, index 0)
LTT: 72 events written in channel task_state (cpu 0, index 0)
LTT: 40 events written in channel module_state (cpu 0, index 0)
LTT: 32 events written in channel softirq_state (cpu 0, index 0)
LTT: 269 events written in channel irq_state (cpu 0, index 0)
LTT: 353 events written in channel syscall_state (cpu 0, index 0)
======================================================
[ INFO: possible circular locking dependency detected ]
3.4.88-WR5.0.1.0_standard #2 Not tainted
-------------------------------------------------------
rmmod/15693 is trying to acquire lock:
(module_mutex){+.+.+.}, at: [<c109660c>] module_get_iter_markers+0x1c/0xa0
but task is already holding lock:
((module_notify_list).rwsem){.+.+.+}, at: [<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 ((module_notify_list).rwsem){.+.+.+}:
[<c108a35e>] lock_acquire+0x7e/0x120
[<c14de70e>] down_read+0x4e/0x60
[<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c1092472>] module_unload_free+0xa2/0xc0
[<c1094c18>] sys_init_module+0x958/0x1c40
[<c14e0b65>] syscall_call+0x7/0xb
-> #0 (module_mutex){+.+.+.}:
[<c10897b8>] __lock_acquire+0x1138/0x1730
[<c108a35e>] lock_acquire+0x7e/0x120
[<c14dd5c6>] mutex_lock_nested+0x66/0x2f0
[<c109660c>] module_get_iter_markers+0x1c/0xa0
[<c10ba928>] marker_get_iter+0x18/0x50
[<c10ba971>] marker_iter_next+0x11/0x20
[<c128a710>] cleanup_control_dir+0x90/0x130
[<c128a7e2>] module_notify+0x32/0xa0
[<c14e45e5>] notifier_call_chain+0x45/0x60
[<c10599f3>] __blocking_notifier_call_chain+0x43/0x70
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c10940a8>] sys_delete_module+0x138/0x220
[<c14e0b65>] syscall_call+0x7/0xb
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock((module_notify_list).rwsem);
lock(module_mutex);
lock((module_notify_list).rwsem);
lock(module_mutex);
*** DEADLOCK ***
1 lock held by rmmod/15693:
#0: ((module_notify_list).rwsem){.+.+.+}, at: [<c10599da>] __blocking_notifier_call_chain+0x2a/0x70
stack backtrace:
Pid: 15693, comm: rmmod Not tainted 3.4.88-WR5.0.1.0_standard #2
Call Trace:
[<c14d7b8e>] print_circular_bug+0x1b4/0x1be
[<c10897b8>] __lock_acquire+0x1138/0x1730
[<c108a35e>] lock_acquire+0x7e/0x120
[<c109660c>] ? module_get_iter_markers+0x1c/0xa0
[<c14dd5c6>] mutex_lock_nested+0x66/0x2f0
[<c109660c>] ? module_get_iter_markers+0x1c/0xa0
[<c11426b6>] ? dput+0x1a6/0x230
[<c14e0852>] ? _raw_spin_unlock+0x22/0x30
[<c109660c>] module_get_iter_markers+0x1c/0xa0
[<c10ba928>] marker_get_iter+0x18/0x50
[<c10ba971>] marker_iter_next+0x11/0x20
[<c128a710>] cleanup_control_dir+0x90/0x130
[<c128a7e2>] module_notify+0x32/0xa0
[<c14e45e5>] notifier_call_chain+0x45/0x60
[<c10599f3>] __blocking_notifier_call_chain+0x43/0x70
[<c1087abb>] ? trace_hardirqs_on+0xb/0x10
[<c1059a3f>] blocking_notifier_call_chain+0x1f/0x30
[<c10940a8>] sys_delete_module+0x138/0x220
[<c11116f6>] ? vm_munmap+0x46/0x60
[<c14e0b98>] ? restore_all+0xf/0xf
[<c14e0b65>] syscall_call+0x7/0xb
LTT : ltt-kprobes exit
LTT : State dump exit
lakemore: control module (built Jul 21 2014 - 13:17:42)
lakemore: registering probe lakemore_config
lakemore: init done
lakemore: unloading control module
lakemore: finished cleanup
**************End of the logs************
Total Tests: 1
Passed: 0
Failed: 1
Skipped: 0
Exception: 0
Manual: 0
/wrlinux-5/wrlinux/configure --enable-board=intel-quark --enable-kernel=standard --enable-rootfs=glibc-std --enable-test=yes --enable-parallel-pkgbuilds=15 --enable-jobs=15 --enable-test=yes --with-layer=/wr-testing/kts,/wr-testing/bts --with-template=feature/odm/aiot-x1000
