Re: [PATCH v4 2/5] x86, traps: Track entry into and exit from IST context

[Andy Lutomirski <luto@amacapital.net>]

On Fri, Jan 30, 2015 at 7:12 PM, Andy Lutomirski <luto@amacapital.net> wrote:
> On Fri, Jan 30, 2015 at 5:28 PM, Sasha Levin <sasha.levin@oracle.com> wrote:
>> On 01/30/2015 02:57 PM, Sasha Levin wrote:
>>> On 01/28/2015 04:02 PM, Andy Lutomirski wrote:
>>>> On Wed, Jan 28, 2015 at 9:48 AM, Paul E. McKenney
>>>> <paulmck@linux.vnet.ibm.com> wrote:
>>>>> On Wed, Jan 28, 2015 at 08:33:06AM -0800, Andy Lutomirski wrote:
>>>>>> On Fri, Jan 23, 2015 at 5:25 PM, Andy Lutomirski <luto@amacapital.net> wrote:
>>>>>>> On Fri, Jan 23, 2015 at 12:48 PM, Sasha Levin <sasha.levin@oracle.com> wrote:
>>>>>>>> On 01/23/2015 01:34 PM, Andy Lutomirski wrote:
>>>>>>>>> On Fri, Jan 23, 2015 at 10:04 AM, Borislav Petkov <bp@alien8.de> wrote:
>>>>>>>>>> On Fri, Jan 23, 2015 at 09:58:01AM -0800, Andy Lutomirski wrote:
>>>>>>>>>>>> [  543.999079] Call Trace:
>>>>>>>>>>>> [  543.999079] dump_stack (lib/dump_stack.c:52)
>>>>>>>>>>>> [  543.999079] lockdep_rcu_suspicious (kernel/locking/lockdep.c:4259)
>>>>>>>>>>>> [  543.999079] atomic_notifier_call_chain (include/linux/rcupdate.h:892 kernel/notifier.c:182 kernel/notifier.c:193)
>>>>>>>>>>>> [  543.999079] ? atomic_notifier_call_chain (kernel/notifier.c:192)
>>>>>>>>>>>> [  543.999079] notify_die (kernel/notifier.c:538)
>>>>>>>>>>>> [  543.999079] ? atomic_notifier_call_chain (kernel/notifier.c:538)
>>>>>>>>>>>> [  543.999079] ? debug_smp_processor_id (lib/smp_processor_id.c:57)
>>>>>>>>>>>> [  543.999079] do_debug (arch/x86/kernel/traps.c:652)
>>>>>>>>>>>> [  543.999079] ? trace_hardirqs_on (kernel/locking/lockdep.c:2609)
>>>>>>>>>>>> [  543.999079] ? do_int3 (arch/x86/kernel/traps.c:610)
>>>>>>>>>>>> [  543.999079] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2554 kernel/locking/lockdep.c:2601)
>>>>>>>>>>>> [  543.999079] debug (arch/x86/kernel/entry_64.S:1310)
>>>>>>>>>>>
>>>>>>>>>>> I don't know how to read this stack trace.  Are we in do_int3,
>>>>>>>>>>> do_debug, or both?  I didn't change do_debug at all.
>>>>>>>>>>
>>>>>>>>>> It looks like we're in do_debug. do_int3 is only on the stack but not
>>>>>>>>>> part of the current frame if I can trust the '?' ...
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> It's possible that an int3 happened and I did something wrong on
>>>>>>>>> return that caused a subsequent do_debug to screw up, but I don't see
>>>>>>>>> how my patch would have caused that.
>>>>>>>>>
>>>>>>>>> Were there any earlier log messages?
>>>>>>>>
>>>>>>>> Nope, nothing odd before or after.
>>>>>>>
>>>>>>> Trinity just survived for a decent amount of time for me with my
>>>>>>> patches, other than a bunch of apparently expected OOM kills.  I have
>>>>>>> no idea how to tell trinity how much memory to use.
>>>>>>
>>>>>> A longer trinity run on a larger VM survived (still with some OOM
>>>>>> kills, but no taint) with these patches.  I suspect that it's a
>>>>>> regression somewhere else in the RCU changes.  I have
>>>>>> CONFIG_PROVE_RCU=y, so I should have seen the failure if it was there,
>>>>>> I think.
>>>>>
>>>>> If by "RCU changes" you mean my changes to the RCU infrastructure, I am
>>>>> going to need more of a hint than I see in this thread thus far.  ;-)
>>>>>
>>>>
>>>> I can't help much, since I can't reproduce the problem.  Presumably if
>>>> it's a bug in -tip, someone else will trigger it, too.
>>>
>>> I'm not sure what to tell you here, I'm not using any weird options for trinity
>>> to reproduce it.
>>>
>>> It doesn't happen to frequently, but I still see it happening.
>>>
>>> Would you like me to try a debug patch or something similar?
>>
>> After talking with Paul we know what's going on here:
>>
>> do_debug() calls ist_enter() to indicate we're running on the interrupt
>> stack. The first think ist_enter() does is:
>
> I wonder whether there's an easy way to trigger this.  Probably a
> watchpoint on the user stack would do the trick.

This is embarrassing.  I just stuck an assertion in do_int3 and I can
reproduce it with int3 from user space.  Patch coming.

>
>>
>>         preempt_count_add(HARDIRQ_OFFSET);
>>
>> After this, as far as the kernel is concerned, we're in interrupt mode
>> so in_interrupt() will return true.
>>
>> Next, we'll call exception_enter() which won't do anything since:
>>
>>         void context_tracking_user_exit(void)
>>         {
>>                 unsigned long flags;
>>
>>                 if (!context_tracking_is_enabled())
>>                         return;
>>
>>                 if (in_interrupt())  <=== This returns true, so nothing else gets done
>>                         return;
>>
>> At this stage we never tell RCU that we exited user mode, but then we
>> try to use it calling the notifiers, which explains the warnings I'm seeing.
>>
>
> Is fixing this as simple as calling exception_enter before
> incrementing the preempt count?  I'll try to have a tested patch
> tomorrow.
>
> Thanks for tracking this down!  I've been out of town since you
> reported this, so I haven't had enough time to track it down myself.
>
> --Andy



-- 
Andy Lutomirski
AMA Capital Management, LLC