[Bug testsuite/10212] New: System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[Bug testsuite/10212] New: System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

On running the following command,
'make installcheck RUNTESTFLAGS=check.exp', after sometime the system hangs and
needs a restart.
Linux kernel version : 2.6.30-rc7-next-20090525
Distro : RHEL 5.3
Architecture : s390x
Systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f

-- 
           Summary: System hangs on running check.exp in systemtap snapshot
                    : 0.9.7/0.141 commit release-0.9.7-167-geee30f4
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: testsuite
        AssignedTo: systemtap at sources dot redhat dot com
        ReportedBy: maranp at linux dot vnet dot ibm dot com


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

------- Additional Comments From maranp at linux dot vnet dot ibm dot com  2009-05-28 09:08 -------
Created an attachment (id=3971)
 --> (http://sourceware.org/bugzilla/attachment.cgi?id=3971&action=view)
systemtap.log

systemtap.log generated on running 'make installcheck RUNTESTFLAGS=check.exp'
is attached.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[ananth at in dot ibm dot com]

------- Additional Comments From ananth at in dot ibm dot com  2009-05-29 04:57 -------
Maran,
* Is the system responsive when the test is running? In other words, is it just
the shell that's running the script that appears hung? Is the rest of the system
usable?
* What does lsmod look like at the time?
* What is the output of 'cat /sys/kernel/debug/kprobes/list'?

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

------- Additional Comments From maranp at linux dot vnet dot ibm dot com  2009-06-05 05:25 -------
Created an attachment (id=3982)
 --> (http://sourceware.org/bugzilla/attachment.cgi?id=3982&action=view)
Kernel BUG messages

Hi,
On running the following command, 

stap testsuite/systemtap.examples/process/sigmon.stp -c "sleep 1" SIGKILL

kernel BUG messages and the corresponding call traces are shown in the s390x
system console (and eventually the kernel hangs). I have compiled those
messages and attached as a file for your perusal. Thanks.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[fche at redhat dot com]

------- Additional Comments From fche at redhat dot com  2009-06-06 14:21 -------
I see signs of two different problems in the kernel bug list.

First, the arch_arm_kprobe->"BUG: using smp_processor_id() in preemptible"
path, it seems like a kernel kprobe-implementation bug, in that it calls
get_kprobe_ctlblk() without an active disable_preempt().  Systemtap could
conceivably work around this by wrapping our kprobe registration calls
in a preempt_disable/enable.


Second, the stp_strncpy_from_user->__might_sleep path, this could be
a runtime bug, or perhaps the absence of a suitable s390x facility to
atomically copy data out.  In fact, runtime/copy.c says:

#elif defined (__s390__) || defined (__s390x__)
#define __stp_strncpy_from_user(dst,src,count,res) \
        do { res = strncpy_from_user(dst, src, count); } while(0)

#endif

which includes a might_sleep().  So it seems the s390x kernel needs
some more code.


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[srikar at linux dot vnet dot ibm dot com]

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |srikar at linux dot vnet dot
                   |                            |ibm dot com


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[mhiramat at redhat dot com]

------- Additional Comments From mhiramat at redhat dot com  2009-06-11 21:56 -------
(In reply to comment #4)
> First, the arch_arm_kprobe->"BUG: using smp_processor_id() in preemptible"
> path, it seems like a kernel kprobe-implementation bug, in that it calls
> get_kprobe_ctlblk() without an active disable_preempt().  Systemtap could
> conceivably work around this by wrapping our kprobe registration calls
> in a preempt_disable/enable.

This seems s390 specific issue. arch_arm/disarm_kprobe() on s390 should be
fixed by using disable_preempt().


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[ananth at in dot ibm dot com]

------- Additional Comments From ananth at in dot ibm dot com  2009-06-12 08:00 -------
Yes, s390 uses heavy iron (stop_machine) to put in and take out the breakpoint.
Patch under test. Will update with results.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[ananth at in dot ibm dot com]

------- Additional Comments From ananth at in dot ibm dot com  2009-06-12 10:26 -------
Found that a simple preempt_disable/enable hack won't suffice for this case.
stop_machine() down the line can schedule(). Investigating further.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

------- Additional Comments From maranp at linux dot vnet dot ibm dot com  2009-06-15 04:44 -------
Created an attachment (id=3997)
 --> (http://sourceware.org/bugzilla/attachment.cgi?id=3997&action=view)
kprobe_test BUG messages

On inserting and removing kprobe_example.ko and kretprobe_example.ko modules,
few Kernel BUG messages are shown. I have compiled them and attached as a text
file. Hope this would be of any help to diagnose the issue.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[ananth at in dot ibm dot com]

------- Additional Comments From ananth at in dot ibm dot com  2009-06-16 11:05 -------
I believe stop_cpu() in kernel/stop_machine.c has a bug.. need someone
conversant in that area to confirm the veracity of this bugfix:

---
 kernel/stop_machine.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Index: linux-2.6.30/kernel/stop_machine.c
===================================================================
--- linux-2.6.30.orig/kernel/stop_machine.c
+++ linux-2.6.30/kernel/stop_machine.c
@@ -68,7 +68,7 @@ static void stop_cpu(struct work_struct 
 {
 	enum stopmachine_state curstate = STOPMACHINE_NONE;
 	struct stop_machine_data *smdata = &idle;
-	int cpu = smp_processor_id();
+	int cpu = raw_smp_processor_id();
 	int err;
 
 	if (!active_cpus) {


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

------- Additional Comments From maranp at linux dot vnet dot ibm dot com  2009-06-23 09:32 -------
The patch given by Heiko for kprobe.c resolved the issue with modprobe
kprobe_example.ko and kprobe sanity test. On applying this patch and testing
check.exp, I see the following issue. One improvement is that the system is not
hanging as before.

# make installcheck RUNTESTFLAGS=check.exp
make  check-DEJAGNU RUNTESTFLAGS="check.exp --tool_opts \'install \'"
make[1]: Entering directory
`/root/maran/systemtap/s390test/systemtap.git/systemtap/testsuite'
srcdir=`CDPATH="${ZSH_VERSION+.}:" && cd . && pwd`; export srcdir; \
	EXPECT=expect; export EXPECT; \
	runtest="env SYSTEMTAP_RUNTIME=/usr/local/share/systemtap/runtime
SYSTEMTAP_TAPSET=/usr/local/share/systemtap/tapset
LD_LIBRARY_PATH=/usr/local/lib/systemtap CRASH_LIBDIR=/usr/local/lib/systemtap
PATH=/usr/local/bin:$PATH SYSTEMTAP_PATH=/usr/local/bin
SYSTEMTAP_INCLUDES=/usr/local/include ./execrc runtest"; \
	if /bin/sh -c "$runtest --version" > /dev/null 2>&1; then \
	  exit_status=0; l='systemtap'; for tool in $l; do \
	    if $runtest  --tool $tool --tool_opts \'\' --srcdir $srcdir check.exp
--tool_opts \'install \'; \
	    then :; else exit_status=1; fi; \
	  done; \
	else echo "WARNING: could not find \`runtest'" 1>&2; :;\
	fi; \
	exit $exit_status
WARNING: Couldn't find the global config file.
kernel location: 
kernel version: 2.6.30jun22-07769-gf234012-dirty
systemtap location: /usr/local/bin/stap
systemtap version: version 0.9.8/0.142 commit release-0.9.8-85-g98a1242 + changes
gcc location: /usr/bin/gcc
gcc version: gcc (GCC) 4.1.2 20080704 (Red Hat 4.1.2-44)
Test Run By root on Tue Jun 23 10:53:36 2009
Native configuration is s390x-ibm-linux

		=== systemtap tests ===

Schedule of variations:
    unix

Running target unix
Using /usr/local/share/dejagnu/baseboards/unix.exp as board description file for
target.
Using /usr/local/share/dejagnu/config/unix.exp as generic interface file for target.
Using
/root/maran/systemtap/s390test/systemtap.git/systemtap/testsuite/config/unix.exp
as tool-and-target-specific interface file.

Host: Linux t6345054 2.6.30jun22-07769-gf234012-dirty #1 SMP PREEMPT Mon Jun 22
16:01:12 CEST 2009 s390x s390x s390x GNU/Linux
Snapshot: version 0.9.8/0.142 commit release-0.9.8-85-g98a1242 + changes
GCC: 4.1.2 [gcc (GCC) 4.1.2 20080704 (Red Hat 4.1.2-44)]
Distro: Red Hat Enterprise Linux Server release 5.3 (Tikanga)

Running
/root/maran/systemtap/s390test/systemtap.git/systemtap/testsuite/systemtap.examples/check.exp
...
FAIL: systemtap.examples/memory/pfaults build
FAIL: systemtap.examples/memory/pfaults run
FAIL: systemtap.examples/process/forktracker run

		=== systemtap Summary ===

# of expected passes		78
# of unexpected failures	3
# of untested testcases		1
make[1]: Leaving directory
`/root/maran/systemtap/s390test/systemtap.git/systemtap/testsuite'
if test -n ""; then mail  < systemtap.sum; fi


"dmesg" on running the above command is pasted below.

BUG: sleeping function called from invalid context at include/linux/kernel.h:157
in_atomic(): 1, irqs_disabled(): 1, pid: 7769, name: sleep
CPU: 1 Tainted: G        W  2.6.30jun22-07769-gf234012-dirty #1
Process sleep (pid: 7769, task: 000000004b4e2198, ksp: 000000004b4ebc08)
0000000000000000 000000004b4eb8a8 0000000000000002 0000000000000000 
       000000004b4eb948 000000004b4eb8c0 000000004b4eb8c0 00000000000486de 
       00000000003f0e50 000000004b4e2510 000000002ef887d0 0000000000000000 
       0000000000000000 000000004b4eb8a8 000000000000000d 000000004b4eb918 
       00000000003f00b8 000000000001647c 000000004b4eb8a8 000000004b4eb8f0 
Call Trace:
([<0000000000016406>] show_trace+0x13a/0x148)
 [<0000000000034eca>] __might_sleep+0x13a/0x164
 [<000003e00318c6e4>] function_user_string+0x108/0x1d8
[stap_cb8a76165dd80354cfa224077e9d9fd0_17578]
 [<000003e003192b08>] probe_1744+0xd8/0x210
[stap_cb8a76165dd80354cfa224077e9d9fd0_17578]
 [<000003e0031921bc>] enter_kprobe_probe+0x22c/0x404
[stap_cb8a76165dd80354cfa224077e9d9fd0_17578]
 [<00000000003ec67e>] aggr_pre_handler+0x86/0x100
 [<00000000003e99cc>] kprobe_exceptions_notify+0x3fc/0x464
 [<00000000003e9e7c>] notifier_call_chain+0x58/0xa0
 [<00000000003e9f0e>] __atomic_notifier_call_chain+0x4a/0x8c
 [<00000000003e9f7a>] atomic_notifier_call_chain+0x2a/0x3c
 [<0000000000069a10>] notify_die+0x4c/0x58
 [<0000000000017d70>] illegal_op+0x74/0x1fc
 [<0000000000028194>] sysc_return+0x0/0x8
 [<00000000000d5c82>] SyS_open+0x2/0x1c
([<0000000000028194>] sysc_return+0x0/0x8)
 [<0000004a44836032>] 0x4a44836032
stap_71b9eba82a713a9a16c1b7682fcf8c6e_6114: systemtap: 0.9.8/0.142, base:
000003e0033d4000, memory: 123158+34322+12176+14000 data+text+ctx+net, probes: 3

stap_776166d0dfaf221f69b760020ce48936_385430: systemtap: 0.9.8/0.142, base:
000003e00270e000, memory: 2458774+561386+30416+14000 data+text+ctx+net, probes: 704
BUG: sleeping function called from invalid context at include/linux/kernel.h:157
in_atomic(): 1, irqs_disabled(): 1, pid: 10728, name: stapio
CPU: 1 Tainted: G        W  2.6.30jun22-07769-gf234012-dirty #1
Process stapio (pid: 10728, task: 0000000013f335c0, ksp: 00000000404b7e00)
0000000000000000 00000000404b7800 0000000000000002 0000000000000000 
       00000000404b78a0 00000000404b7818 00000000404b7818 00000000000486de 
       00000000003f0e50 0000000013f33938 00000000359ac0f8 0000000000000000 
       0000000000000000 00000000404b7800 000000000000000d 00000000404b7870 
       00000000003f00b8 000000000001647c 00000000404b7800 00000000404b7848 
Call Trace:
([<0000000000016406>] show_trace+0x13a/0x148)
 [<0000000000034eca>] __might_sleep+0x13a/0x164
 [<000003e002710f4a>] _stp_strncpy_from_user+0x3e/0x60
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e00272a15a>] probe_1852+0x226/0x4f8
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e002720168>] enter_kprobe_probe+0x224/0x3fc
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<00000000003ec67e>] aggr_pre_handler+0x86/0x100
 [<00000000003e99cc>] kprobe_exceptions_notify+0x3fc/0x464
 [<00000000003e9e7c>] notifier_call_chain+0x58/0xa0
 [<00000000003e9f0e>] __atomic_notifier_call_chain+0x4a/0x8c
 [<00000000003e9f7a>] atomic_notifier_call_chain+0x2a/0x3c
 [<0000000000069a10>] notify_die+0x4c/0x58
 [<0000000000017d70>] illegal_op+0x74/0x1fc
 [<0000000000028194>] sysc_return+0x0/0x8
 [<00000000000df122>] do_execve+0x2/0x3ac
([<000000000001b19e>] sys_execve+0x3e/0xa8)
 [<000000000002818e>] sysc_noemu+0x10/0x16
 [<0000004a448f13f0>] 0x4a448f13f0
BUG: sleeping function called from invalid context at include/linux/kernel.h:157
in_atomic(): 1, irqs_disabled(): 1, pid: 10730, name: stapio
CPU: 1 Tainted: G        W  2.6.30jun22-07769-gf234012-dirty #1
Process stapio (pid: 10730, task: 0000000013f32198, ksp: 000000004048f8c8)
0000000000000000 000000004048f848 0000000000000002 0000000000000000 
       000000004048f8e8 000000004048f860 000000004048f860 00000000000486de 
       00000000003f0e50 0000000013f32510 000000004048fe10 0000000000000000 
       0000000000000000 000000004048f848 000000000000000d 000000004048f8b8 
       00000000003f00b8 000000000001647c 000000004048f848 000000004048f890 
Call Trace:
([<0000000000016406>] show_trace+0x13a/0x148)
 [<0000000000034eca>] __might_sleep+0x13a/0x164
 [<000003e002710f4a>] _stp_strncpy_from_user+0x3e/0x60
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e00271106c>] function_user_string+0x100/0x1b8
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e00274f73c>] probe_2416+0xdc/0x388
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e002720168>] enter_kprobe_probe+0x224/0x3fc
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<00000000003ec67e>] aggr_pre_handler+0x86/0x100
 [<00000000003e99cc>] kprobe_exceptions_notify+0x3fc/0x464
 [<00000000003e9e7c>] notifier_call_chain+0x58/0xa0
 [<00000000003e9f0e>] __atomic_notifier_call_chain+0x4a/0x8c
 [<00000000003e9f7a>] atomic_notifier_call_chain+0x2a/0x3c
 [<0000000000069a10>] notify_die+0x4c/0x58
 [<0000000000017d70>] illegal_op+0x74/0x1fc
 [<0000000000028194>] sysc_return+0x0/0x8
 [<00000000000d8a52>] SyS_write+0x2/0x88
([<0000000000030c20>] kretprobe_trampoline+0x0/0x4)
 [<0000004a449d8d24>] 0x4a449d8d24
BUG: sleeping function called from invalid context at include/linux/kernel.h:157
in_atomic(): 1, irqs_disabled(): 1, pid: 10730, name: stapio
CPU: 1 Tainted: G        W  2.6.30jun22-07769-gf234012-dirty #1
Process stapio (pid: 10730, task: 0000000013f32198, ksp: 000000004048f8c8)
0000000000000000 000000004048f848 0000000000000002 0000000000000000 
       000000004048f8e8 000000004048f860 000000004048f860 00000000000486de 
       00000000003f0e50 0000000013f32510 000000004048fe10 0000000000000000 
       0000000000000000 000000004048f848 000000000000000d 000000004048f8b8 
       00000000003f00b8 000000000001647c 000000004048f848 000000004048f890 
Call Trace:
([<0000000000016406>] show_trace+0x13a/0x148)
 [<0000000000034eca>] __might_sleep+0x13a/0x164
 [<000003e002710f4a>] _stp_strncpy_from_user+0x3e/0x60
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e00271106c>] function_user_string+0x100/0x1b8
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e00274f73c>] probe_2416+0xdc/0x388
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<000003e002720168>] enter_kprobe_probe+0x224/0x3fc
[stap_776166d0dfaf221f69b760020ce48936_385430]
 [<00000000003ec67e>] aggr_pre_handler+0x86/0x100
 [<00000000003e99cc>] kprobe_exceptions_notify+0x3fc/0x464
 [<00000000003e9e7c>] notifier_call_chain+0x58/0xa0
 [<00000000003e9f0e>] __atomic_notifier_call_chain+0x4a/0x8c
 [<00000000003e9f7a>] atomic_notifier_call_chain+0x2a/0x3c
 [<0000000000069a10>] notify_die+0x4c/0x58
 [<0000000000017d70>] illegal_op+0x74/0x1fc
 [<0000000000028194>] sysc_return+0x0/0x8
 [<00000000000d8a52>] SyS_write+0x2/0x88
([<0000000000030c20>] kretprobe_trampoline+0x0/0x4)
 [<0000004a449d8d24>] 0x4a449d8d24
stap_54dac69e50c7c61034709699ac3a30a6_13700: systemtap: 0.9.8/0.142, base:
000003e002c90000, memory: 121560+35400+8176+14000 data+text+ctx+net, probes: 3
stap_378345d837ee11dbc9221ea0c193f29d_2066: systemtap: 0.9.8/0.142, base:
000003e0034c3000, memory: 2034428+31556+9136+14000 data+text+ctx+net, probes: 2


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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

[Bug testsuite/10212] System hangs on running check.exp in systemtap snapshot : 0.9.7/0.141 commit release-0.9.7-167-geee30f4

[maranp at linux dot vnet dot ibm dot com]

------- Additional Comments From maranp at linux dot vnet dot ibm dot com  2009-06-23 09:49 -------
The calltraces mentioned in the previous update, occur only when running from
systemtap modules and not on running sample kprobe modules.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=10212

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