Re: Sleeping BUG in khugepaged for i586

Vlastimil Babka
2017-06-07T07:19:40Z

On 06/06/2017 05:01 PM, Larry Finger wrote:
> On 06/06/2017 09:02 AM, Vlastimil Babka wrote:
>> On 06/05/2017 11:44 PM, Andrew Morton wrote:
>>> On Sat, 3 Jun 2017 14:24:26 -0500 Larry Finger <Larry.Finger@lwfinger.net> wrote:
>>>
>>>> I recently turned on locking diagnostics for a Dell Latitude D600 laptop, which
>>>> requires a 32-bit kernel. In the log I found the following:
>>>>
>>>> BUG: sleeping function called from invalid context at mm/khugepaged.c:655
>>>> in_atomic(): 1, irqs_disabled(): 0, pid: 20, name: khugepaged
>>>> 1 lock held by khugepaged/20:
>>>> #0: (&mm->mmap_sem){++++++}, at: [<c03d6609>]
>>>> collapse_huge_page.isra.47+0x439/0x1240
>>>> CPU: 0 PID: 20 Comm: khugepaged Tainted: G W
>>
>> W means thre was WARN earler. Could be related... Got logs?
>
> When I grabbed a splat, I got the last one in my log. The first one shows "Not
> tainted".
>
>>
>>>> 4.12.0-rc1-wl-12125-g952a068 #80
>>
>> What is "wl-12125-g952a068"? What patches on top of mainline?
>
> I found this while chasing a problem with one of the wireless drivers. For that
> reason I use Kalle Valo's wireless-testing-next, which happens to be the only
> kernel tree I have on this laptop. I'm reasonably certain that the extra updates
> are not the cause of the problem as the first one appears before any of the
> wireless drivers are loaded, but I will pull a clean copy of mainline to test
> that assumption.
>
>>>> Hardware name: Dell Computer Corporation Latitude D600
>>>> /03U652, BIOS A05 05/29/2003
>>>> Call Trace:
>>>> dump_stack+0x76/0xb2
>>>> ___might_sleep+0x174/0x230
>>>> collapse_huge_page.isra.47+0xacf/0x1240
>>>> khugepaged_scan_mm_slot+0x41e/0xc00
>>>> ? _raw_spin_lock+0x46/0x50
>>>> khugepaged+0x277/0x4f0
>>>> ? prepare_to_wait_event+0xe0/0xe0
>>>> kthread+0xeb/0x120
>>>> ? khugepaged_scan_mm_slot+0xc00/0xc00
>>>> ? kthread_create_on_node+0x30/0x30
>>>> ret_from_fork+0x21/0x30
>>>>
>>>> I have no idea when this problem was introduced. Of course, I will test any
>>>> proposed fixes.
>>>>
>>>
>>> Odd. There's nothing wrong with cond_resched() while holding mmap_sem.
>>> It looks like khugepaged forgot to do a spin_unlock somewhere and we
>>> leaked a preempt_count.
>>
>> Hmm I'd expect such spin lock to be reported together with mmap_sem in
>> the debugging "locks held" message?
>
> My bisection of the problem is about half done. My latest good version is commit
> 7b8cd33 and the latest bad one is 2ea659a. Only about 7 steps to go.

Hmm, your bisection will most likely just find commit 338a16ba15495
which added the cond_resched() at mm/khugepaged.c:655. CCing David who
added it.