[DRBD-user] strange drbd bug

[Lars Ellenberg]

On Tue, Oct 14, 2014 at 06:07:21PM +0200, Bart Van Assche wrote:
> On 10/14/14 17:08, Lars Ellenberg wrote:
> >On Tue, Oct 14, 2014 at 03:27:56PM +0200, Matteo Tescione wrote:
> >>Discussed this topic with Bart from SCST, he suggested:
> >>"To me this looks like a DRBD bug. If a timeout of a DRBD request occurs
> >>the DRBD timeout handler (request_timer_fn()) is called, that function
> >>grabs a spinlock and next calls kthread_create_on_node() with that
> >>spinlock held.
> >
> >Well, no, our request_timer_fn does nothing like that.
> >At least it is not supposed to, and I don't see a code path
> >leading to anything like that.
> 
> Hello Lars,
> 
> Matteo reported that this occurred with DRBD version 8.4.4 (see also
> http://sourceforge.net/p/scst/mailman/message/32928699/). My
> conclusion from the stack trace posted by Matteo is that the call
> chain was as follows:

Yes, I've seen the stack trace. But:

> -> run_timer_softirq()
> -> call_timer_fn
> -> request_timer_fn()
> -> _drbd_set_state()
> -> __drbd_set_state()
> -> _drbd_thread_stop() (locks the &thi->t_lock spinlock)
> -> drbd_thread_start()
> -> kthread_create_on_node()
> -> wait_for_completion()
> 
> In other words, wait_for_completion() is not only called from
> soft-IRQ context but also with a spinlock held. Does this make sense
> to you ?

Absolutely not.

But wait....

_drbd_thread_stop takes a "wait" parameter.
It's a helper function for drbd_thread_stop()
and for drbd_thread_stop_nowait().
It is possible that "somewhere" we call drbd_thread_stop()
where we should call drbd_thread_stop_nowait().
But I don't see where that would be.

Same helper function is called for drbd_thread_restart_nowait().
I'd say that's what happens here.

So from the state change triggered by the request_timer_fn
in softirq context ("current" is "swapper" as seen from the other mail),
we trigger a drbd_thread_restart_nowait().

Which calls kthread_create -> drbd_thread_setup

And *there* it bombs out.

Yes, I see it happening now.

I just wonder why it does not happen *always* then, *every* time that
request timer expires and causes the peer to be kicked out?

maybe something changed around kthread_create as well.

Or maybe we just have been lucky for the last few years,
and the "wake_up_process(); wait_on_completion()" in kthread_run
just so happened to never need to call schedule,
because it always took the fast path.

workaround for now: don't use that request timer...
(ko-count=0)

Or chose to *disconnect* (Go "StandAlone"), instead of trying to reconnect,
once that timer expires.
(see below).

We'll have to think about how to fix it best.

	Lars


diff --git a/drbd/drbd_state.c b/drbd/drbd_state.c
index e3f6569..aca4210 100644
--- a/drbd/drbd_state.c
+++ b/drbd/drbd_state.c
@@ -1433,7 +1433,7 @@ _drbd_set_state(struct drbd_device *device, union drbd_state ns,
        /* Upon network failure, we need to restart the receiver. */
        if (os.conn > C_WF_CONNECTION &&
            ns.conn <= C_TEAR_DOWN && ns.conn >= C_TIMEOUT)
-               drbd_thread_restart_nowait(&connection->receiver);
+               drbd_thread_stop_nowait(&connection->receiver);

        /* Resume AL writing if we get a connection */
        if (os.conn < C_CONNECTED && ns.conn >= C_CONNECTED) {