This is the mail archive of the systemtap@sourceware.org mailing list for the systemtap project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

[PATCH] itrace spin lock fix


Back in August Frank reported a problem running the itrace test on an x86-64 machine. This was caused by an uninitialized spin_lock and possibly by some utrace callouts that didn't need in the spin_lock protected regions. This patch fixes that problem.

On an RHEL5 x86-64 machine, I got:

BUG: soft lockup - CPU#0 stuck for 10s! [ls_15964:16126]
CPU 0:
Modules linked in: stap_7c70ff0a5aa33e45a459d750475957f4_763(U) xt_tcpudp iptable_nat ip_nat ip_conntrack nfnet
link ip_tables x_tables xfrm_nalgo crypto_api hidp l2cap bluetooth nfs lockd fscache nfs_acl sunrpc dm_multipat
h video sbs backlight i2c_ec button battery asus_acpi acpi_memhotplug ac lp floppy ata_piix libata scsi_mod i2c
_piix4 i2c_core pcspkr ide_cd 8139too parport_pc 8139cp mii parport serio_raw cdrom dm_snapshot dm_zero dm_mirr
or dm_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 16126, comm: ls_15964 Tainted: G      2.6.18-92.1.1.el5 #1
RIP: 0010:[<ffffffff80064b54>]  [<ffffffff80064b54>] .text.lock.spinlock+0x2/0x30
RSP: 0018:ffff81001d279dd0  EFLAGS: 00000286
RAX: 0000000000003efe RBX: ffff8100104b2900 RCX: 0000000000000000
RDX: ffff8100104b2900 RSI: ffff8100188ee860 RDI: ffffffff883f64c0
RBP: ffffffff80061e22 R08: ffff81001d278000 R09: 0000000000000001
R10: ffff810016f059c8 R11: 0000000300000000 R12: 0000000000000282
R13: a3754e699d64d231 R14: ffff81000563c000 R15: 0000000000003efe
FS:  0000000000000000(0000) GS:ffffffff8039f000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007fff904eeaf9 CR3: 000000000dff2000 CR4: 00000000000006e0

Call Trace:
 [<ffffffff883e137f>] :stap_7c70ff0a5aa33e45a459d750475957f4_763:usr_itrace_init+0x92/0x17d
 [<ffffffff883e51e8>] :stap_7c70ff0a5aa33e45a459d750475957f4_763:__stp_utrace_attach_match_tsk+0x17c/0x22e
 [<ffffffff883e52e7>] :stap_7c70ff0a5aa33e45a459d750475957f4_763:__stp_utrace_task_finder_report_exec+0x4d/0x4f
 [<ffffffff800bd589>] utrace_report_exec+0x58/0x187
 [<ffffffff8003f49b>] search_binary_handler+0x171/0x26d
 [<ffffffff8003e950>] do_execve+0x18c/0x243
 [<ffffffff80054760>] sys_execve+0x36/0x4c


This could have been caused by create_itrace_info's use of an uninitialized spin_lock. It is not clear that a spinlock is appropriate at all, considering which of the protected calls could block.


- FChE

-- Dave Nomura LTC Linux Power Toolchain

diff -paurN old/ChangeLog new/ChangeLog
--- old/ChangeLog	2008-10-22 16:19:10.000000000 -0700
+++ new/ChangeLog	2008-10-22 16:30:32.000000000 -0700
@@ -1,3 +1,7 @@
+2008-10-22  Dave Nomura  <dcnltc@us.ibm.com>
+
+	* runtimes/itrace.c: remove utrace calls from spin_lock regions
+
 2008-10-20	Elliott Baron  <ebaron@redhat.com>
 
 	PR6851
diff -paurN old/runtime/itrace.c new/runtime/itrace.c
--- old/runtime/itrace.c	2008-10-22 16:19:10.000000000 -0700
+++ new/runtime/itrace.c	2008-10-21 14:34:58.000000000 -0700
@@ -137,6 +137,7 @@ static struct itrace_info *create_itrace
 	struct stap_itrace_probe *itrace_probe)
 {
 	struct itrace_info *ui;
+	struct utrace_attached_engine *engine;
 
 	if (debug)
 		printk(KERN_INFO "create_itrace_info: tid=%d\n", tsk->pid);
@@ -151,23 +152,23 @@ static struct itrace_info *create_itrace
 #endif
 	INIT_LIST_HEAD(&ui->link);
 
-	/* push ui onto usr_itrace_info */
-	spin_lock(&itrace_lock);
-	list_add(&ui->link, &usr_itrace_info);
-
 	/* attach a single stepping engine */
-	ui->engine = utrace_attach(ui->tsk, UTRACE_ATTACH_CREATE, &utrace_ops, ui);
-	if (IS_ERR(ui->engine)) {
+	engine = utrace_attach(ui->tsk, UTRACE_ATTACH_CREATE, &utrace_ops, ui);
+	if (IS_ERR(engine)) {
 		printk(KERN_ERR "utrace_attach returns %ld\n",
-			PTR_ERR(ui->engine));
-		ui = NULL;
-	} else {
-		utrace_set_flags(tsk, ui->engine, ui->engine->flags |
-			ui->step_flag |
-			UTRACE_EVENT(CLONE) | UTRACE_EVENT_SIGNAL_ALL |
-			UTRACE_EVENT(DEATH));
+			PTR_ERR(engine));
+		return NULL;
 	}
+
+	/* push ui onto usr_itrace_info */
+	spin_lock(&itrace_lock);
+	list_add(&ui->link, &usr_itrace_info);
 	spin_unlock(&itrace_lock);
+
+	utrace_set_flags(tsk, engine, engine->flags | step_flag |
+		UTRACE_EVENT(CLONE) | UTRACE_EVENT_SIGNAL_ALL |
+		UTRACE_EVENT(DEATH));
+
 	return ui;
 }
 
@@ -192,6 +193,8 @@ int usr_itrace_init(int single_step, pid
 	struct itrace_info *ui;
 	struct task_struct *tsk;
 
+	spin_lock_init(&itrace_lock);
+
 	rcu_read_lock();
 	tsk = find_task_by_pid(tid);
 	if (!tsk) {
@@ -210,11 +213,6 @@ int usr_itrace_init(int single_step, pid
 	put_task_struct(tsk);
 	rcu_read_unlock();
 
-	spin_lock_init(&itrace_lock);
-
-	/* set initial state */
-	spin_lock(&itrace_lock);
-	spin_unlock(&itrace_lock);
 	printk(KERN_INFO "usr_itrace_init: completed for tid = %d\n", tid);
 
 	return 0;
@@ -223,6 +221,8 @@ int usr_itrace_init(int single_step, pid
 void static remove_usr_itrace_info(struct itrace_info *ui)
 {
 	struct itrace_info *tmp;
+	struct task_struct *tsk;
+	struct utrace_attached_engine *engine;
 
 	if (!ui)
 		return;
@@ -231,11 +231,14 @@ void static remove_usr_itrace_info(struc
 		printk(KERN_INFO "remove_usr_itrace_info: tid=%d\n", ui->tid);
 
 	spin_lock(&itrace_lock);
-	if (ui->tsk && ui->engine) {
-		(void) utrace_detach(ui->tsk, ui->engine);
-	}
+	tsk = ui->tsk;
+	engine = ui->engine;
 	list_del(&ui->link);
 	spin_unlock(&itrace_lock);
+
+	if (tsk && engine) {
+		(void) utrace_detach(tsk, engine);
+	}
 	kfree(ui);
 }
 

Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]