Re: Sleeping thread (tid 100033, pid 16): panic in FreeBSD 10.0-CURRENT/amd64 r228662

On Tue, Dec 20, 2011 at 5:52 AM, John Baldwin <jhb_at_freebsd.org> wrote:
> On Saturday, December 17, 2011 10:41:15 pm mdf_at_freebsd.org wrote:
>> On Sat, Dec 17, 2011 at 5:45 PM, Alexander Kabaev <kabaev_at_gmail.com> wrote:
>> > On Sun, 18 Dec 2011 01:09:00 +0100
>> > "O. Hartmann" <ohartman_at_zedat.fu-berlin.de> wrote:
>> >
>> >> Sleeping thread (tid 100033, pid 16) owns a non sleepable lock
>> >> panic: sleeping thread
>> >> cpuid = 0
>> >>
>> >> PID 16 is always USB on my box.
>> >
>> > You really need to give us a backtrace when you quote panics. It is
>> > impossible to make any sense of the above panic message without more
>> > context.
>>
>> In the case of this panic, the stack of the thread which panics is
>> useless; it's someone trying to propagate priority that discovered it.
>>  A backtrace on tid 100033 would be useful.
>>
>> With WITNESS enabled, it's possible to have this panic display the
>> stack of the incorrectly sleeping thread at the time it acquired the
>> lock, as well, but this code isn't in CURRENT or any release.  I have
>> a patch at $WORK I can dig up on Monday.
>
> Huh?  The stock kernel dumps a stack trace of the offending thread if you have
> DDB enabled:
>
>                /*
>                 * If the thread is asleep, then we are probably about
>                 * to deadlock.  To make debugging this easier, just
>                 * panic and tell the user which thread misbehaved so
>                 * they can hopefully get a stack trace from the truly
>                 * misbehaving thread.
>                 */
>                if (TD_IS_SLEEPING(td)) {
>                        printf(
>                "Sleeping thread (tid %d, pid %d) owns a non-sleepable lock\n",
>                            td->td_tid, td->td_proc->p_pid);
> #ifdef DDB
>                        db_trace_thread(td, -1);
> #endif
>                        panic("sleeping thread");
>                }

Hmm, maybe this wasn't in 7, or maybe I'm just remembering that we
added code to print *which* lock it holds (using WITNESS data).  I do
recall that this panic alone was often not sufficient to debug the
problem.

Thanks,
matthew


> It may be that we can make use of the STACK API here instead to output this
> trace even when DDB isn't enabled.  The patch below tries to do that
> (untested).  It does some odd thigns though since it is effectively running
> from a panic context already, so it uses a statically allocated 'struct stack'
> rather than using stack_create() and uses stack_print_ddb() since it is
> holding spin locks and can't possibly grab an sx lock:
>
> Index: subr_turnstile.c
> ===================================================================
> --- subr_turnstile.c    (revision 228534)
> +++ subr_turnstile.c    (working copy)
> _at__at_ -72,6 +72,7 _at__at_ __FBSDID("$FreeBSD$");
>  #include <sys/proc.h>
>  #include <sys/queue.h>
>  #include <sys/sched.h>
> +#include <sys/stack.h>
>  #include <sys/sysctl.h>
>  #include <sys/turnstile.h>
>
> _at__at_ -175,6 +176,7 _at__at_ static void turnstile_fini(void *mem, int size);
>  static void
>  propagate_priority(struct thread *td)
>  {
> +       static struct stack st;
>        struct turnstile *ts;
>        int pri;
>
> _at__at_ -217,8 +219,10 _at__at_ propagate_priority(struct thread *td)
>                        printf(
>                "Sleeping thread (tid %d, pid %d) owns a non-sleepable lock\n",
>                            td->td_tid, td->td_proc->p_pid);
> -#ifdef DDB
> -                       db_trace_thread(td, -1);
> +#ifdef STACK
> +                       stack_zero(&st);
> +                       stack_save_td(&st, td);
> +                       stack_print_ddb(&st);
>  #endif
>                        panic("sleeping thread");
>                }
>
> --
> John Baldwin