[Bug runtime/24416] Tests stuck in uprobes_onthefly.exp

["wcohen at redhat dot com" <sourceware-bugzilla at sourceware dot org>]

https://sourceware.org/bugzilla/show_bug.cgi?id=24416

--- Comment #5 from William Cohen <wcohen at redhat dot com> ---
Created attachment 11722
  --> https://sourceware.org/bugzilla/attachment.cgi?id=11722&action=edit
reproducer script pr24416b.stp

Copied the uprobes_onthefly.x when the uprobes_onthefly.exp was running and had
the modified uprobes_onthefly.exp spit out the scripts running.

Now going removing bits and pieces otf_stress_max_iter_5000.stp to see what
part of the script is causing the problem. This one has the println removed. 
Then run the following to reproduce the problem:

$ ./uprobes_onthefly.x &
$ sudo stap pr24416b.stp -D STP_ON_THE_FLY_INTERVAL=100000
--suppress-handler-errors -w -DDEBUG_STP_ON_THE_FLY -DMAXMAPENTRIES=100000
-DSTP_NO_OVERLOAD

End up with the following in the output of dmesg:

[  276.951464] stap_0066c50c29eeff618305b0bdc059b380_5_1600: loading
out-of-tree module taints kernel.
[  276.951853] stap_0066c50c29eeff618305b0bdc059b380_5_1600: module
verification failed: signature and/or required key missing - tainting kernel
[  277.135240] stap_0066c50c29eeff618305b0bdc059b380_5_1600 (pr24416a.stp):
systemtap: 4.1/0.176, base: 000000007b148777, memory:
768data/448text/0ctx/2063net/11246alloc kb, probes: 1073
[  492.715121] INFO: task kworker/0:2:149 blocked for more than 122 seconds.
[  492.715130]       Tainted: G           OE     5.1.0-0.rc3.git1.1.fc31.x86_64
#1
[  492.715131] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  492.715133] kworker/0:2     D13080   149      2 0x80000000
[  492.715139] Workqueue: events kprobe_optimizer
[  492.715141] Call Trace:
[  492.715148]  ? __schedule+0x36a/0xbe0
[  492.715152]  ? __lock_acquire+0xd6d/0x1060
[  492.715155]  ? wait_for_completion+0x10d/0x170
[  492.715158]  schedule+0x39/0x80
[  492.715160]  schedule_timeout+0x317/0x4e0
[  492.715165]  ? wait_for_completion+0x10d/0x170
[  492.715167]  ? mark_held_locks+0x50/0x80
[  492.715169]  ? _raw_spin_unlock_irq+0x29/0x40
[  492.715173]  ? wait_for_completion+0x10d/0x170
[  492.715175]  wait_for_completion+0x12c/0x170
[  492.715177]  ? wake_up_q+0x60/0x60
[  492.715182]  __wait_rcu_gp+0x157/0x170
[  492.715186]  synchronize_rcu_tasks+0x35/0x50
[  492.715188]  ? rcu_read_lock_held+0x60/0x60
[  492.715190]  ? __bpf_trace_rcu_utilization+0x10/0x10
[  492.715195]  ? wait_for_completion+0x48/0x170
[  492.715197]  kprobe_optimizer+0x12b/0x280
[  492.715201]  process_one_work+0x272/0x5e0
[  492.715208]  worker_thread+0x50/0x3b0
[  492.715213]  kthread+0x108/0x140
[  492.715215]  ? process_one_work+0x5e0/0x5e0
[  492.715216]  ? kthread_park+0x90/0x90
[  492.715219]  ret_from_fork+0x3a/0x50
[  492.715249] INFO: task stapio:1600 blocked for more than 122 seconds.
[  492.715250]       Tainted: G           OE     5.1.0-0.rc3.git1.1.fc31.x86_64
#1
[  492.715251] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  492.715252] stapio          D13168  1600   1595 0x80000000
[  492.715255] Call Trace:
[  492.715259]  ? __schedule+0x36a/0xbe0
[  492.715261]  ? kvm_sched_clock_read+0x14/0x30
[  492.715267]  schedule+0x39/0x80
[  492.715269]  schedule_preempt_disabled+0x11/0x20
[  492.715271]  __mutex_lock+0x312/0x930
[  492.715275]  ? register_kprobe+0x1b2/0x630
[  492.715283]  ? register_kprobe+0x1b2/0x630
[  492.715285]  register_kprobe+0x1b2/0x630
[  492.715305]  ? _stp_kmodule_relocate.part.0+0x82/0xb0
[stap_0066c50c29eeff618305b0bdc059b380_5_1600]
[  492.715322]  stapkp_register_probe+0xdd/0x1d0
[stap_0066c50c29eeff618305b0bdc059b380_5_1600]
[  492.715346]  ? _stp_ctl_write_cmd.cold+0x1df/0x209d
[stap_0066c50c29eeff618305b0bdc059b380_5_1600]
[  492.715354]  ? full_proxy_write+0x56/0x80
[  492.715358]  ? vfs_write+0xcb/0x1c0
[  492.715361]  ? ksys_write+0x52/0xc0
[  492.715365]  ? do_syscall_64+0x5c/0xa0
[  492.715368]  ? entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  492.715376] 
               Showing all locks held in the system:
[  492.715379] 1 lock held by khungtaskd/18:
[  492.715381]  #0: 0000000090410079 (rcu_read_lock){....}, at:
debug_show_all_locks+0x15/0x174
[  492.715386] 5 locks held by kworker/0:2/149:
[  492.715387]  #0: 00000000071df764 ((wq_completion)events){+.+.}, at:
process_one_work+0x1e9/0x5e0
[  492.715391]  #1: 0000000039ff1fe5 ((optimizing_work).work){+.+.}, at:
process_one_work+0x1e9/0x5e0
[  492.715394]  #2: 00000000eb5a22fb (kprobe_mutex){+.+.}, at:
kprobe_optimizer+0x19/0x280
[  492.715397]  #3: 000000004d3336d3 (cpu_hotplug_lock.rw_sem){++++}, at:
kprobe_optimizer+0x1e/0x280
[  492.715399]  #4: 0000000090fda3fd (module_mutex){+.+.}, at:
kprobe_optimizer+0x2c/0x280
[  492.715409] 4 locks held by stapio/1600:
[  492.715410]  #0: 0000000090ca70bd (&f->f_pos_lock){+.+.}, at:
__fdget_pos+0x4d/0x60
[  492.715414]  #1: 00000000bcaba9e5 (sb_writers#16){.+.+}, at:
vfs_write+0x152/0x1c0
[  492.715417]  #2: 0000000087e54606 (cmd_mutex){+.+.}, at:
_stp_ctl_write_cmd+0xe0/0xb20 [stap_0066c50c29eeff618305b0bdc059b380_5_1600]
[  492.715431]  #3: 00000000eb5a22fb (kprobe_mutex){+.+.}, at:
register_kprobe+0x1b2/0x630

[  492.715435] =============================================

-- 
You are receiving this mail because:
You are the assignee for the bug.