Re: [BUG] NULL pointer deref with rcutorture

Paul E. McKenney
2009-01-05T02:28:50Z

On Mon, Jan 05, 2009 at 12:38:55AM +0100, Eric Sesterhenn wrote:
> hi,
>
> * Paul E. McKenney (paulmck@linux.vnet.ibm.com) wrote:
> > On Sun, Jan 04, 2009 at 03:57:26PM +0100, Eric Sesterhenn wrote:
> > >
> > > Just tell me what i need to do, I am not really familiar with ftrace.
> > > I am only able to test 2.6.28-04980-gb58602a, since current -git is not
> > > able to boot on this box :|
> >
> > Very cool!
> >
> > The idea is to have __call_rcu() in kernel/rcutree.c record the
> > address of the callback (argument "head") and the function (argument
> > "func"). In rcu_do_batch(), just before invoking list->func(list),
> > also record the address of the callback ("list") and the function
> > (again, "func").
> >
> > The new ftrace package has some mechanisms for doing this, but there is
> > always the old-fashioned way of using printk(), for example in
> > rcu_do_batch():
> >
> > prefetch(next);
> > if (rcu_dump_callbacks)
> > printk("rcu_head=%p, func=%p\n", list, func);
> > list->func(list);
> >
> > Initialize rcu_dump_callbacks to zero, then use a small kernel module
> > (or some such) to set it to one just before running your test.
>
> i did it via the ugly printk and captured it via netconsole

Good stuff!!!

> for the box with rcutree you can find the log here:
> http://www.cccmz.de/~snakebyte/200.log
> The interesting part seems start at 155.858923, thats when I load
> the rcutorture module

When I download this, I see an 82.100963 immediately followed by an
167.894017, no 155.858923. Do I have the right log?

> with http://www.cccmz.de/~snakebyte/200_1.log i had another try,
> actually saw a rcu_do_batch: rcu_head=d1907720, func=(null) in the traces,
> box went into unresponsive mode afterwards

Interesting. The original function is 0xd1902ad0, passed to __call_rcu()
at 157.364214 -- would you be able to tell me what function that
corresponds to? (Looks to me like a module, perhaps rcutorture?)

Whatever function it is, the rcu_head definitely got corrupted some
time during the 8 milliseconds or so that the callback was waiting for
a grace period. However, it did just fine being invoked several times
beforehand -- this is a very popular RCU callback function, it appears.

My guess is that the ensuing CPU 0 stall messages are due to CPU 0
having a heart attack trying to execute at address 0.

Are you swapping over NFS, or is the netpoll_send_udp() just garbage on
the stack?

> And just in case it helps somehow: http://www.cccmz.de/~snakebyte/200_3.log

Hmmm... The main recent change to kernel/rcutorture.c is the addition
of a reboot notifier, so that rcutorture can shut itself down gracefully
should the system go down while rcutorture is still running. This panic
occurs in rcu_torture_stutter(), which is shown below:

static int
rcu_torture_stutter(void *arg)
{
VERBOSE_PRINTK_STRING("rcu_torture_stutter task started");
do {
schedule_timeout_interruptible(stutter * HZ);
stutter_pause_test = 1;
if (!kthread_should_stop() && !fullstop)
schedule_timeout_interruptible(stutter * HZ);
stutter_pause_test = 0;
} while (!kthread_should_stop() && !fullstop);
VERBOSE_PRINTK_STRING("rcu_torture_stutter task stopping");
return 0;
}

I don't see any reason why this function would transfer control to
location 0x60, though I do see a bug in the new shutdown code. I
don't expect this to make any difference, but a patch is included
nevertheless.

> for the one with rcupreemt you can find the log here:
> http://www.cccmz.de/~snakebyte/201.log
> rcutorture is loaded at 87.312399

Hmmm... Offset 0x60 seems to be a common thread. This lets
rcu_torture_ops off the hook, since it isn't that large.

Anyway, could you give the attached patch a go, even though I cannot see
how it would help? ;-)

Do you get the same error running Classic RCU?

Thanx, Paul

> Greetings, Eric

Fix an rcutorture bug that prevents the shutdown notifier from ever
actually having any effect, due to the fact that kthreads ignore all
signals.

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---

rcutorture.c | 18 ++++++++----------
1 file changed, 8 insertions(+), 10 deletions(-)

diff --git a/kernel/rcutorture.c b/kernel/rcutorture.c
index b310655..d54111c 100644
--- a/kernel/rcutorture.c
+++ b/kernel/rcutorture.c
@@ -136,7 +136,7 @@ static int stutter_pause_test = 0;
#endif
int rcutorture_runnable = RCUTORTURE_RUNNABLE_INIT;

-#define FULLSTOP_SIGNALED 1 /* Bail due to signal. */
+#define FULLSTOP_SHUTDOWN 1 /* Bail due to system shutdown/panic. */
#define FULLSTOP_CLEANUP 2 /* Orderly shutdown. */
static int fullstop; /* stop generating callbacks at test end. */
DEFINE_MUTEX(fullstop_mutex); /* protect fullstop transitions and */
@@ -151,12 +151,10 @@ rcutorture_shutdown_notify(struct notifier_block *unused1,
{
if (fullstop)
return NOTIFY_DONE;
- if (signal_pending(current)) {
- mutex_lock(&fullstop_mutex);
- if (!ACCESS_ONCE(fullstop))
- fullstop = FULLSTOP_SIGNALED;
- mutex_unlock(&fullstop_mutex);
- }
+ mutex_lock(&fullstop_mutex);
+ if (!fullstop)
+ fullstop = FULLSTOP_SHUTDOWN;
+ mutex_unlock(&fullstop_mutex);
return NOTIFY_DONE;
}

@@ -624,7 +622,7 @@ rcu_torture_writer(void *arg)
rcu_stutter_wait();
} while (!kthread_should_stop() && !fullstop);
VERBOSE_PRINTK_STRING("rcu_torture_writer task stopping");
- while (!kthread_should_stop() && fullstop != FULLSTOP_SIGNALED)
+ while (!kthread_should_stop() && fullstop != FULLSTOP_SHUTDOWN)
schedule_timeout_uninterruptible(1);
return 0;
}
@@ -649,7 +647,7 @@ rcu_torture_fakewriter(void *arg)
} while (!kthread_should_stop() && !fullstop);

VERBOSE_PRINTK_STRING("rcu_torture_fakewriter task stopping");
- while (!kthread_should_stop() && fullstop != FULLSTOP_SIGNALED)
+ while (!kthread_should_stop() && fullstop != FULLSTOP_SHUTDOWN)
schedule_timeout_uninterruptible(1);
return 0;
}
@@ -759,7 +757,7 @@ rcu_torture_reader(void *arg)
VERBOSE_PRINTK_STRING("rcu_torture_reader task stopping");
if (irqreader && cur_ops->irqcapable)
del_timer_sync(&t);
- while (!kthread_should_stop() && fullstop != FULLSTOP_SIGNALED)
+ while (!kthread_should_stop() && fullstop != FULLSTOP_SHUTDOWN)
schedule_timeout_uninterruptible(1);
return 0;
}