[PATCH] fix for 'spinlock bad magic' error with itrace probe point

[Maynard Johnson]

After Dave Nomura first committed the itrace support back in August 2008, Frank 
reported in an Aug 6 posting that the itrace test failed on x86_64 with "BUG: 
soft lockup - CPU#0 stuck for 10s!".  Using a current SystemTap git pull on a 
ppc64 Fedora 11 (rawhide) system, I have encountered a 'spinlock bad magic' 
error when testing the itrace probe point.  The system was configured with 
various debugging options (e.g., CONFIG_LOCKDEP, CONFIG_DEBUG_SPINLOCK).  This 
error does not occur on systems running production kernels vs a debug kernel.

I believe the same underlying bug (an uninitialized spinlock in 
systemtap/runtime/itrace.c) was the cause of both symptoms -- the one Frank 
reported and the one I'm seeing now.  The attached patch fixes this problem.

For the current problem, an error  message is sent to the screen, with more 
detailed information sent to the system log as follows:

---- Screen output -----
Message from syslogd@localhost at Mar 18 10:38:16 ...
  kernel:BUG: spinlock bad magic on CPU#1, probeme4/2703 (Not tainted)

Message from syslogd@localhost at Mar 18 10:38:16 ...
  kernel: lock: d000000000c0e758, .magic: 00000000, .owner: probeme4/2703, 
.owner_cpu: 1

---- System log -----
Mar 17 20:19:19 localhost kernel: create_itrace_info: tid=3725
Mar 17 20:19:19 localhost kernel: BUG: spinlock bad magic on CPU#0, 
probeme4/3725 (Not tainted)
Mar 17 20:19:19 localhost kernel: lock: d000000000f16758, .magic: 00000000, 
.owner: probeme4/3725, .owner_cpu: 0
Mar 17 20:19:19 localhost kernel: Call Trace:
Mar 17 20:19:19 localhost kernel: [c00000002cba76c0] [c000000000012530] 
.show_stack+0x98/0x188 (unreliable)
Mar 17 20:19:19 localhost kernel: [c00000002cba7770] [c00000000060db1c] 
.dump_stack+0x28/0x3c
Mar 17 20:19:19 localhost kernel: [c00000002cba77f0] [c0000000002b5120] 
.spin_bug+0xd4/0x108
Mar 17 20:19:19 localhost kernel: [c00000002cba78a0] [c0000000002b5190] 
._raw_spin_unlock+0x3c/0xd8
Mar 17 20:19:19 localhost kernel: [c00000002cba7930] [c000000000601114] 
._spin_unlock+0x48/0x64
Mar 17 20:19:19 localhost kernel: [c00000002cba79d0] [d000000000ee89a8] 
._stp_itrace_probe_cb+0x168/0x360 [stap_484930766b74f315cd7f061cecaed62f_46246]
Mar 17 20:19:19 localhost kernel: [c00000002cba7a90] [d000000000ee5278] 
.__stp_utrace_task_finder_target_quiesce+0x178/0x394 
[stap_484930766b74f315cd7f061cecaed62f_46246]
Mar 17 20:19:19 localhost kernel: [c00000002cba7b70] [c0000000001060a8] 
.start_callback+0x90/0x11c
Mar 17 20:19:19 localhost kernel: [c00000002cba7c20] [c00000000010862c] 
.utrace_resume+0xfc/0x160
Mar 17 20:19:19 localhost kernel: [c00000002cba7ce0] [c000000000015298] 
.do_signal+0x308/0x334
Mar 17 20:19:19 localhost kernel: [c00000002cba7e30] [c000000000008c48] 
do_work+0x24/0x28
Mar 17 20:19:19 localhost kernel: usr_itrace_init: completed for tid = 3725
Mar 17 20:19:20 localhost kernel: cleanup_usr_itrace called
Mar 17 20:19:20 localhost kernel: remove_usr_itrace_info: tid=3725
Mar 17 20:19:42 localhost kernel: create_itrace_info: tid=3742
Mar 17 20:19:42 localhost kernel: usr_itrace_init: completed for tid = 3742

=====================================================================
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: spinlock-badmagic.patch
URL: <http://sourceware.org/pipermail/systemtap/attachments/20090318/f7ef0b26/attachment.ksh>