oops in __delayacct_blkio_ticks with 2.6.18-rc4

oops in __delayacct_blkio_ticks with 2.6.18-rc4

[Olaf Hering]

https://bugzilla.novell.com/show_bug.cgi?id=200526


tsk->delays became 0 after or during the call to spinlock. _spin_lock cant be
called with 0.

pear login: Oops: Kernel access of bad area, sig: 11 [#1]
SMP NR_CPUS=128 NUMA
Modules linked in: pppoe pppox ppp_generic slhc joydev st ide_cd nfs lockd
nfs_acl sunrpc autofs ipv6 sg pdc202xx_new e1000 dm_mod raid0 ipr
firmware_class sr_mod cd
rom sd_mod scsi_mod
NIP: C00000000009D614 LR: C00000000009D604 CTR: 0000000000000000
REGS: c0000000bb307630 TRAP: 0300   Not tainted (2.6.18-rc4-20060810162421-ppc64)
MSR: 8000000000009032 <EE,ME,IR,DR>  CR: 24042422  XER: 20000001
DAR: 0000000000000028, DSISR: 0000000040000000
TASK = c0000002e0542ae0[24051] 'w' THREAD: c0000000bb304000 CPU: 5
GPR00: C00000000009D604 C0000000BB3078B0 C000000000620130 C0000002E308EAA0
GPR04: C0000000BB307AD0 C0000000BB307AD8 C0000000BB307AEF C0000002D2A29480
GPR08: C00000011A482380 0000000000989680 0000000000000000 0000000000000000
GPR12: 0000000000000000 C000000000476B80 0000000000000000 0000000000000000
GPR16: 0000000000000000 0000000000000000 0000000000000011 0000000000400044
GPR20: 0000000000000000 0000000000005DED 0000000029B33DD2 000000000000FF15
GPR24: C00000013B42D500 0000000000000007 0000000000010002 0000000000000000
GPR28: 0000000000000000 C0000002D2A29480 C0000000004CAC98 C0000002D2A29480
NIP [C00000000009D614] .__delayacct_blkio_ticks+0x34/0x6c
LR [C00000000009D604] .__delayacct_blkio_ticks+0x24/0x6c
Call Trace:
[C0000000BB3078B0] [C00000000009D604] .__delayacct_blkio_ticks+0x24/0x6c (unreliable)
[C0000000BB307940] [C000000000128320] .do_task_stat+0x4b0/0x6fc
[C0000000BB307C40] [C000000000124F4C] .proc_info_read+0x9c/0x144
[C0000000BB307CF0] [C0000000000D394C] .vfs_read+0x118/0x200
[C0000000BB307D90] [C0000000000D3E30] .sys_read+0x4c/0x8c
[C0000000BB307E30] [C00000000000871C] syscall_exit+0x0/0x40
Instruction dump:
fba1ffe8 7c7d1b78 f8010010 f821ff71 60000000 60000000 e8630818 482e2c49
60000000 e97d0818 3d200098 61299680 <e86b0028> e80b0030 7c630214 7c634b92

Re: oops in __delayacct_blkio_ticks with 2.6.18-rc4

[Shailabh Nagar]

Olaf Hering wrote:
> https://bugzilla.novell.com/show_bug.cgi?id=200526
>

Thanks for detecting this.

I suspect the oops is caused by a reading of /proc/<tgid>/stat for some task
that is late in exit. Currently tsk->delays is being freed up too early (before
the tsk is removed from the tasklist).

Could you try the patch below ? It was unclear from the bug what userspace
actions were being done to reproduce the oops - I suspect some kind of
reading of /proc/.../stat for all processes ?

>
> tsk->delays became 0 after or during the call to spinlock. _spin_lock cant be
> called with 0.
>

<snip>

> Call Trace:
> [C0000000BB3078B0] [C00000000009D604] .__delayacct_blkio_ticks+0x24/0x6c (unreliable)
> [C0000000BB307940] [C000000000128320] .do_task_stat+0x4b0/0x6fc
> [C0000000BB307C40] [C000000000124F4C] .proc_info_read+0x9c/0x144
> [C0000000BB307CF0] [C0000000000D394C] .vfs_read+0x118/0x200
> [C0000000BB307D90] [C0000000000D3E30] .sys_read+0x4c/0x8c
> [C0000000BB307E30] [C00000000000871C] syscall_exit+0x0/0x40




Cleanup allocation and freeing of tsk->delays used by delay accounting.

Currently tsk->delays is getting freed too early in task exit
which can cause a NULL tsk->delays to get accessed via reading
of /proc/<tgid>/stats. The patch fixes this problem by freeing
tsk->delays closer to when task_struct itself is freed up. As a result,
it also eliminates the use of tsk->delays_lock which was only being
used (inadequately) to safeguard access to tsk->delays
while a task was exiting.

The patch also cleans up tsk->delays allocations after a bad fork which
was missing earlier and might lead to leaks.

Signed-Off-By: Shailabh Nagar <nagar@watson.ibm.com>

 include/linux/delayacct.h |   10 +++++++---
 include/linux/sched.h     |    1 -
 kernel/delayacct.c        |   16 ----------------
 kernel/exit.c             |    1 -
 kernel/fork.c             |    6 ++++--
 5 files changed, 11 insertions(+), 23 deletions(-)

Index: linux-2.6.18-rc4/kernel/fork.c
===================================================================
--- linux-2.6.18-rc4.orig/kernel/fork.c	2006-08-22 14:42:08.000000000 -0400
+++ linux-2.6.18-rc4/kernel/fork.c	2006-08-22 14:52:52.000000000 -0400
@@ -117,6 +117,7 @@ void __put_task_struct(struct task_struc
 	security_task_free(tsk);
 	free_uid(tsk->user);
 	put_group_info(tsk->group_info);
+	delayacct_tsk_free(tsk);

 	if (!profile_handoff_task(tsk))
 		free_task(tsk);
@@ -1011,7 +1012,7 @@ static struct task_struct *copy_process(
 	retval = -EFAULT;
 	if (clone_flags & CLONE_PARENT_SETTID)
 		if (put_user(p->pid, parent_tidptr))
-			goto bad_fork_cleanup;
+			goto bad_fork_cleanup_delays_binfmt;

 	INIT_LIST_HEAD(&p->children);
 	INIT_LIST_HEAD(&p->sibling);
@@ -1277,7 +1278,8 @@ bad_fork_cleanup_policy:
 bad_fork_cleanup_cpuset:
 #endif
 	cpuset_exit(p);
-bad_fork_cleanup:
+bad_fork_cleanup_delays_binfmt:
+	delayacct_tsk_free(p);
 	if (p->binfmt)
 		module_put(p->binfmt->module);
 bad_fork_cleanup_put_domain:
Index: linux-2.6.18-rc4/include/linux/delayacct.h
===================================================================
--- linux-2.6.18-rc4.orig/include/linux/delayacct.h	2006-08-22 14:42:03.000000000 -0400
+++ linux-2.6.18-rc4/include/linux/delayacct.h	2006-08-22 14:52:52.000000000 -0400
@@ -59,10 +59,14 @@ static inline void delayacct_tsk_init(st
 		__delayacct_tsk_init(tsk);
 }

-static inline void delayacct_tsk_exit(struct task_struct *tsk)
+/* Free tsk->delays. Called from bad fork and __put_task_struct
+ * where there's no risk of tsk->delays being accessed elsewhere
+ */
+static inline void delayacct_tsk_free(struct task_struct *tsk)
 {
 	if (tsk->delays)
-		__delayacct_tsk_exit(tsk);
+		kmem_cache_free(delayacct_cache, tsk->delays);
+	tsk->delays = NULL;
 }

 static inline void delayacct_blkio_start(void)
@@ -101,7 +105,7 @@ static inline void delayacct_init(void)
 {}
 static inline void delayacct_tsk_init(struct task_struct *tsk)
 {}
-static inline void delayacct_tsk_exit(struct task_struct *tsk)
+static inline void delayacct_tsk_free(struct task_struct *tsk)
 {}
 static inline void delayacct_blkio_start(void)
 {}
Index: linux-2.6.18-rc4/include/linux/sched.h
===================================================================
--- linux-2.6.18-rc4.orig/include/linux/sched.h	2006-08-22 14:42:03.000000000 -0400
+++ linux-2.6.18-rc4/include/linux/sched.h	2006-08-22 14:52:52.000000000 -0400
@@ -994,7 +994,6 @@ struct task_struct {
 	 */
 	struct pipe_inode_info *splice_pipe;
 #ifdef	CONFIG_TASK_DELAY_ACCT
-	spinlock_t delays_lock;
 	struct task_delay_info *delays;
 #endif
 };
Index: linux-2.6.18-rc4/kernel/exit.c
===================================================================
--- linux-2.6.18-rc4.orig/kernel/exit.c	2006-08-22 14:42:03.000000000 -0400
+++ linux-2.6.18-rc4/kernel/exit.c	2006-08-22 14:52:52.000000000 -0400
@@ -908,7 +908,6 @@ fastcall NORET_TYPE void do_exit(long co
 		audit_free(tsk);
 	taskstats_exit_send(tsk, tidstats, group_dead, mycpu);
 	taskstats_exit_free(tidstats);
-	delayacct_tsk_exit(tsk);

 	exit_mm(tsk);

Index: linux-2.6.18-rc4/kernel/delayacct.c
===================================================================
--- linux-2.6.18-rc4.orig/kernel/delayacct.c	2006-08-22 14:42:03.000000000 -0400
+++ linux-2.6.18-rc4/kernel/delayacct.c	2006-08-22 14:52:52.000000000 -0400
@@ -41,24 +41,11 @@ void delayacct_init(void)

 void __delayacct_tsk_init(struct task_struct *tsk)
 {
-	spin_lock_init(&tsk->delays_lock);
-	/* No need to acquire tsk->delays_lock for allocation here unless
-	   __delayacct_tsk_init called after tsk is attached to tasklist
-	*/
 	tsk->delays = kmem_cache_zalloc(delayacct_cache, SLAB_KERNEL);
 	if (tsk->delays)
 		spin_lock_init(&tsk->delays->lock);
 }

-void __delayacct_tsk_exit(struct task_struct *tsk)
-{
-	struct task_delay_info *delays = tsk->delays;
-	spin_lock(&tsk->delays_lock);
-	tsk->delays = NULL;
-	spin_unlock(&tsk->delays_lock);
-	kmem_cache_free(delayacct_cache, delays);
-}
-
 /*
  * Start accounting for a delay statistic using
  * its starting timestamp (@start)
@@ -118,8 +105,6 @@ int __delayacct_add_tsk(struct taskstats
 	struct timespec ts;
 	unsigned long t1,t2,t3;

-	spin_lock(&tsk->delays_lock);
-
 	/* Though tsk->delays accessed later, early exit avoids
 	 * unnecessary returning of other data
 	 */
@@ -161,7 +146,6 @@ int __delayacct_add_tsk(struct taskstats
 	spin_unlock(&tsk->delays->lock);

 done:
-	spin_unlock(&tsk->delays_lock);
 	return 0;
 }

Re: oops in __delayacct_blkio_ticks with 2.6.18-rc4

[Olaf Hering]

On Tue, Aug 22, Shailabh Nagar wrote:

> Olaf Hering wrote:
> > https://bugzilla.novell.com/show_bug.cgi?id=200526
> >
> 
> Thanks for detecting this.
> 
> I suspect the oops is caused by a reading of /proc/<tgid>/stat for some task
> that is late in exit. Currently tsk->delays is being freed up too early (before
> the tsk is removed from the tasklist).
> 
> Could you try the patch below ? It was unclear from the bug what userspace
> actions were being done to reproduce the oops - I suspect some kind of
> reading of /proc/.../stat for all processes ?

I dont have a way to trigger it. The commands were 'w' and 'pstree'.

Re: oops in __delayacct_blkio_ticks with 2.6.18-rc4

[Shailabh Nagar]

Olaf Hering wrote:
> On Tue, Aug 22, Shailabh Nagar wrote:
> 
> 
>>Olaf Hering wrote:
>>
>>>https://bugzilla.novell.com/show_bug.cgi?id=200526
>>>
>>
>>Thanks for detecting this.
>>
>>I suspect the oops is caused by a reading of /proc/<tgid>/stat for some task
>>that is late in exit. Currently tsk->delays is being freed up too early (before
>>the tsk is removed from the tasklist).
>>
>>Could you try the patch below ? It was unclear from the bug what userspace
>>actions were being done to reproduce the oops - I suspect some kind of
>>reading of /proc/.../stat for all processes ?
> 
> 
> I dont have a way to trigger it. The commands were 'w' and 'pstree'.

Ok. Using the following two commands allowed the original oops to be
triggered on an 8-way pretty quickly:

while : ; do usleep 10 > /dev/null ; done

while : ; do cat /proc/[0-9]???*/stat ; done

(where the regex for catching the newly forking/exiting tasks
can be adjusted to the right range of ids being spawned by the
first command)

Applying the patch I sent solves the problem. I'm doing some more
testing and will submit the patch formally shortly.

Thanks,
Shailabh