Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1243085 > unrolled thread

Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

Started byNikolay Borisov <kernel@kyup.com>
First post2015-10-09 09:30 +0200
Last post2015-10-16 15:00 +0200
Articles 11 — 3 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-09 09:30 +0200
    Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI "Hillf Danton" <hillf.zj@alibaba-inc.com> - 2015-10-09 09:40 +0200
      Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-09 10:10 +0200
        Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local  interrupts disabled and page-draining IPI Jan Kara <jack@suse.cz> - 2015-10-12 15:50 +0200
          Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-12 17:00 +0200
            Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local  interrupts disabled and page-draining IPI Jan Kara <jack@suse.cz> - 2015-10-13 10:20 +0200
              Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-13 12:40 +0200
                Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local  interrupts disabled and page-draining IPI Jan Kara <jack@suse.cz> - 2015-10-13 15:20 +0200
                  Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-14 11:10 +0200
                  Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts  disabled and page-draining IPI Nikolay Borisov <kernel@kyup.com> - 2015-10-16 10:10 +0200
                    Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local  interrupts disabled and page-draining IPI Jan Kara <jack@suse.cz> - 2015-10-16 15:00 +0200

#1243085 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-09 09:30 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qhAhP-3Jz-11@gated-at.bofh.it>

On 10/09/2015 10:19 AM, Hillf Danton wrote:
>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>  			if (bio->bi_error)
>>  				buffer_io_error(bh);
>>  		} while ((bh = bh->b_this_page) != head);
>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>  		local_irq_restore(flags);
> 
> What if it takes 100ms to unlock after IRQ restored?

I'm not sure I understand in what direction you are going? Care to
elaborate?

>> +		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>  		if (!under_io) {
>>  #ifdef CONFIG_EXT4_FS_ENCRYPTION
>>  			if (ctx)
>> --
>> 2.5.0
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [next] | [standalone]

#1243091 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

From"Hillf Danton" <hillf.zj@alibaba-inc.com>
Date2015-10-09 09:40 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qhArv-3UI-9@gated-at.bofh.it>
In reply to#1243085
> >> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
> >>  			if (bio->bi_error)
> >>  				buffer_io_error(bh);
> >>  		} while ((bh = bh->b_this_page) != head);
> >> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>  		local_irq_restore(flags);
> >
> > What if it takes 100ms to unlock after IRQ restored?
> 
> I'm not sure I understand in what direction you are going? Care to
> elaborate?
> 
Your change introduces extra time cost the lock waiter has to pay in
the case that irq happens before the lock is released.

> >> +		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>  		if (!under_io) {
> >>  #ifdef CONFIG_EXT4_FS_ENCRYPTION
> >>  			if (ctx)
> >> --
> >> 2.5.0
> >

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1243099

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-09 10:10 +0200
Message-ID<qhAUy-4Iv-1@gated-at.bofh.it>
In reply to#1243091
On 10/09/2015 10:37 AM, Hillf Danton wrote:
>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>>>  			if (bio->bi_error)
>>>>  				buffer_io_error(bh);
>>>>  		} while ((bh = bh->b_this_page) != head);
>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>  		local_irq_restore(flags);
>>>
>>> What if it takes 100ms to unlock after IRQ restored?
>>
>> I'm not sure I understand in what direction you are going? Care to
>> elaborate?
>>
> Your change introduces extra time cost the lock waiter has to pay in
> the case that irq happens before the lock is released.

[CC filesystem and mm people. For reference the thread starts here:
 http://thread.gmane.org/gmane.linux.kernel/2056996 ]

Right, I see what you mean and it's a good point but when doing the
patches I was striving for correctness and starting a discussion, hence
the RFC. In any case I'd personally choose correctness over performance
always ;).

As I'm not an fs/ext4 expert and have added the relevant parties (please
use reply-all from now on so that the thread is not being cut in the
middle) who will be able to say whether it impact is going to be that
big. I guess in this particular code path worrying about this is prudent
as writeback sounds like a heavily used path.

Maybe the problem should be approached from a different angle e.g.
drain_all_pages and its reliance on the fact that the IPI will always be
delivered in some finite amount of time? But what if a cpu with disabled
interrupts is waiting on the task issuing the IPI?

> 
>>>> +		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>  		if (!under_io) {
>>>>  #ifdef CONFIG_EXT4_FS_ENCRYPTION
>>>>  			if (ctx)
>>>> --
>>>> 2.5.0
>>>
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1244698 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

FromJan Kara <jack@suse.cz>
Date2015-10-12 15:50 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qiLEd-zW-5@gated-at.bofh.it>
In reply to#1243099
On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
> On 10/09/2015 10:37 AM, Hillf Danton wrote:
> >>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
> >>>>  			if (bio->bi_error)
> >>>>  				buffer_io_error(bh);
> >>>>  		} while ((bh = bh->b_this_page) != head);
> >>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>>>  		local_irq_restore(flags);
> >>>
> >>> What if it takes 100ms to unlock after IRQ restored?
> >>
> >> I'm not sure I understand in what direction you are going? Care to
> >> elaborate?
> >>
> > Your change introduces extra time cost the lock waiter has to pay in
> > the case that irq happens before the lock is released.
> 
> [CC filesystem and mm people. For reference the thread starts here:
>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
> 
> Right, I see what you mean and it's a good point but when doing the
> patches I was striving for correctness and starting a discussion, hence
> the RFC. In any case I'd personally choose correctness over performance
> always ;).
> 
> As I'm not an fs/ext4 expert and have added the relevant parties (please
> use reply-all from now on so that the thread is not being cut in the
> middle) who will be able to say whether it impact is going to be that
> big. I guess in this particular code path worrying about this is prudent
> as writeback sounds like a heavily used path.
> 
> Maybe the problem should be approached from a different angle e.g.
> drain_all_pages and its reliance on the fact that the IPI will always be
> delivered in some finite amount of time? But what if a cpu with disabled
> interrupts is waiting on the task issuing the IPI?

So I have looked through your patch and also original report (thread starts
here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
__block_write_full_page_endio() call but that cannot really be the case.
BH_Uptodate_Lock is used only in IO completion handlers -
end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
really should be some end_io function running on some other CPU which holds
BH_Uptodate_Lock for that buffer.

BTW: I suppose the filesystem uses 4k blocksize, doesn't it?

								Honza

> >>>> +		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>>>  		if (!under_io) {
> >>>>  #ifdef CONFIG_EXT4_FS_ENCRYPTION
> >>>>  			if (ctx)
> >>>> --
> >>>> 2.5.0
> >>>
> > 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-fsdevel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
-- 
Jan Kara <jack@suse.com>
SUSE Labs, CR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1244789

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-12 17:00 +0200
Message-ID<qiMJY-29w-15@gated-at.bofh.it>
In reply to#1244698
Hello and thanks for the reply,

On 10/12/2015 04:40 PM, Jan Kara wrote:
> On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
>> On 10/09/2015 10:37 AM, Hillf Danton wrote:
>>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>>>>>  			if (bio->bi_error)
>>>>>>  				buffer_io_error(bh);
>>>>>>  		} while ((bh = bh->b_this_page) != head);
>>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>>>  		local_irq_restore(flags);
>>>>>
>>>>> What if it takes 100ms to unlock after IRQ restored?
>>>>
>>>> I'm not sure I understand in what direction you are going? Care to
>>>> elaborate?
>>>>
>>> Your change introduces extra time cost the lock waiter has to pay in
>>> the case that irq happens before the lock is released.
>>
>> [CC filesystem and mm people. For reference the thread starts here:
>>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
>>
>> Right, I see what you mean and it's a good point but when doing the
>> patches I was striving for correctness and starting a discussion, hence
>> the RFC. In any case I'd personally choose correctness over performance
>> always ;).
>>
>> As I'm not an fs/ext4 expert and have added the relevant parties (please
>> use reply-all from now on so that the thread is not being cut in the
>> middle) who will be able to say whether it impact is going to be that
>> big. I guess in this particular code path worrying about this is prudent
>> as writeback sounds like a heavily used path.
>>
>> Maybe the problem should be approached from a different angle e.g.
>> drain_all_pages and its reliance on the fact that the IPI will always be
>> delivered in some finite amount of time? But what if a cpu with disabled
>> interrupts is waiting on the task issuing the IPI?
> 
> So I have looked through your patch and also original report (thread starts
> here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
> been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
> on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
> __block_write_full_page_endio() call but that cannot really be the case.
> BH_Uptodate_Lock is used only in IO completion handlers -
> end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
> really should be some end_io function running on some other CPU which holds
> BH_Uptodate_Lock for that buffer.

I did check all the call traces of the current processes on the machine
at the time of the hard lockup and none of the 3 functions you mentioned
were in any of the call chains. But while I was looking the code of
end_buffer_async_write and in the comments I saw it was mentioned that
those completion handler were called from __block_write_full_page_endio
so that's what pointed my attention to that function. But you are right
that it doesn't take the BH lock.

Furthermore the fact that the BH_Async_Write flag is set points me in
the direction that end_buffer_async_write should have been executing but
as I said issuing "bt" for all the tasks didn't show this function.

I'm beginning to wonder if it's possible that a single bit memory error
has crept up, but this still seems like a long shot...

Btw I think in any case the spin_lock patch is wrong as this code can be
called from within softirq context and we do want to be interrupt safe
at that point.

> 
> BTW: I suppose the filesystem uses 4k blocksize, doesn't it?

Unfortunately I cannot tell you with 100% certainty, since on this
server there are multiple block devices with blocksize either 1k or 4k.
So it is one of these. If you know a way to extract this information
from a vmcore file I'd be happy to do it.

> 
> 								Honza
> 
>>>>>> +		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>>>  		if (!under_io) {
>>>>>>  #ifdef CONFIG_EXT4_FS_ENCRYPTION
>>>>>>  			if (ctx)
>>>>>> --
>>>>>> 2.5.0
>>>>>
>>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-fsdevel" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1245447 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

FromJan Kara <jack@suse.cz>
Date2015-10-13 10:20 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qj2Yq-Lw-25@gated-at.bofh.it>
In reply to#1244789
On Mon 12-10-15 17:51:07, Nikolay Borisov wrote:
> Hello and thanks for the reply,
> 
> On 10/12/2015 04:40 PM, Jan Kara wrote:
> > On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
> >> On 10/09/2015 10:37 AM, Hillf Danton wrote:
> >>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
> >>>>>>  			if (bio->bi_error)
> >>>>>>  				buffer_io_error(bh);
> >>>>>>  		} while ((bh = bh->b_this_page) != head);
> >>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>>>>>  		local_irq_restore(flags);
> >>>>>
> >>>>> What if it takes 100ms to unlock after IRQ restored?
> >>>>
> >>>> I'm not sure I understand in what direction you are going? Care to
> >>>> elaborate?
> >>>>
> >>> Your change introduces extra time cost the lock waiter has to pay in
> >>> the case that irq happens before the lock is released.
> >>
> >> [CC filesystem and mm people. For reference the thread starts here:
> >>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
> >>
> >> Right, I see what you mean and it's a good point but when doing the
> >> patches I was striving for correctness and starting a discussion, hence
> >> the RFC. In any case I'd personally choose correctness over performance
> >> always ;).
> >>
> >> As I'm not an fs/ext4 expert and have added the relevant parties (please
> >> use reply-all from now on so that the thread is not being cut in the
> >> middle) who will be able to say whether it impact is going to be that
> >> big. I guess in this particular code path worrying about this is prudent
> >> as writeback sounds like a heavily used path.
> >>
> >> Maybe the problem should be approached from a different angle e.g.
> >> drain_all_pages and its reliance on the fact that the IPI will always be
> >> delivered in some finite amount of time? But what if a cpu with disabled
> >> interrupts is waiting on the task issuing the IPI?
> > 
> > So I have looked through your patch and also original report (thread starts
> > here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
> > been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
> > on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
> > __block_write_full_page_endio() call but that cannot really be the case.
> > BH_Uptodate_Lock is used only in IO completion handlers -
> > end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
> > really should be some end_io function running on some other CPU which holds
> > BH_Uptodate_Lock for that buffer.
> 
> I did check all the call traces of the current processes on the machine
> at the time of the hard lockup and none of the 3 functions you mentioned
> were in any of the call chains. But while I was looking the code of
> end_buffer_async_write and in the comments I saw it was mentioned that
> those completion handler were called from __block_write_full_page_endio
> so that's what pointed my attention to that function. But you are right
> that it doesn't take the BH lock.
> 
> Furthermore the fact that the BH_Async_Write flag is set points me in
> the direction that end_buffer_async_write should have been executing but
> as I said issuing "bt" for all the tasks didn't show this function.

Actually ext4_bio_write_page() also sets BH_Async_Write so that seems like
a more likely place where that flag got set since ext4_finish_bio() was
then handling IO completion.

> I'm beginning to wonder if it's possible that a single bit memory error
> has crept up, but this still seems like a long shot...

Yup. Possible but a long shot. Is the problem reproducible in any way?

> Btw I think in any case the spin_lock patch is wrong as this code can be
> called from within softirq context and we do want to be interrupt safe
> at that point.

Agreed, that patch is definitely wrong.

> > BTW: I suppose the filesystem uses 4k blocksize, doesn't it?
> 
> Unfortunately I cannot tell you with 100% certainty, since on this
> server there are multiple block devices with blocksize either 1k or 4k.
> So it is one of these. If you know a way to extract this information
> from a vmcore file I'd be happy to do it.

Well, if you have a crashdump, then bh->b_size is the block size. So just
check that for the bh we are spinning on.

								Honza
-- 
Jan Kara <jack@suse.com>
SUSE Labs, CR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1245561

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-13 12:40 +0200
Message-ID<qj59U-3SV-17@gated-at.bofh.it>
In reply to#1245447

On 10/13/2015 11:15 AM, Jan Kara wrote:
> On Mon 12-10-15 17:51:07, Nikolay Borisov wrote:
>> Hello and thanks for the reply,
>>
>> On 10/12/2015 04:40 PM, Jan Kara wrote:
>>> On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
>>>> On 10/09/2015 10:37 AM, Hillf Danton wrote:
>>>>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>>>>>>>  			if (bio->bi_error)
>>>>>>>>  				buffer_io_error(bh);
>>>>>>>>  		} while ((bh = bh->b_this_page) != head);
>>>>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>>>>>  		local_irq_restore(flags);
>>>>>>>
>>>>>>> What if it takes 100ms to unlock after IRQ restored?
>>>>>>
>>>>>> I'm not sure I understand in what direction you are going? Care to
>>>>>> elaborate?
>>>>>>
>>>>> Your change introduces extra time cost the lock waiter has to pay in
>>>>> the case that irq happens before the lock is released.
>>>>
>>>> [CC filesystem and mm people. For reference the thread starts here:
>>>>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
>>>>
>>>> Right, I see what you mean and it's a good point but when doing the
>>>> patches I was striving for correctness and starting a discussion, hence
>>>> the RFC. In any case I'd personally choose correctness over performance
>>>> always ;).
>>>>
>>>> As I'm not an fs/ext4 expert and have added the relevant parties (please
>>>> use reply-all from now on so that the thread is not being cut in the
>>>> middle) who will be able to say whether it impact is going to be that
>>>> big. I guess in this particular code path worrying about this is prudent
>>>> as writeback sounds like a heavily used path.
>>>>
>>>> Maybe the problem should be approached from a different angle e.g.
>>>> drain_all_pages and its reliance on the fact that the IPI will always be
>>>> delivered in some finite amount of time? But what if a cpu with disabled
>>>> interrupts is waiting on the task issuing the IPI?
>>>
>>> So I have looked through your patch and also original report (thread starts
>>> here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
>>> been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
>>> on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
>>> __block_write_full_page_endio() call but that cannot really be the case.
>>> BH_Uptodate_Lock is used only in IO completion handlers -
>>> end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
>>> really should be some end_io function running on some other CPU which holds
>>> BH_Uptodate_Lock for that buffer.
>>
>> I did check all the call traces of the current processes on the machine
>> at the time of the hard lockup and none of the 3 functions you mentioned
>> were in any of the call chains. But while I was looking the code of
>> end_buffer_async_write and in the comments I saw it was mentioned that
>> those completion handler were called from __block_write_full_page_endio
>> so that's what pointed my attention to that function. But you are right
>> that it doesn't take the BH lock.
>>
>> Furthermore the fact that the BH_Async_Write flag is set points me in
>> the direction that end_buffer_async_write should have been executing but
>> as I said issuing "bt" for all the tasks didn't show this function.
> 
> Actually ext4_bio_write_page() also sets BH_Async_Write so that seems like
> a more likely place where that flag got set since ext4_finish_bio() was
> then handling IO completion.
> 
>> I'm beginning to wonder if it's possible that a single bit memory error
>> has crept up, but this still seems like a long shot...
> 
> Yup. Possible but a long shot. Is the problem reproducible in any way?

Okay, I rule out hardware issue since a different server today 
experienced the same hard lockup. One thing which looks 
suspicious to me are the repetitions of bio_endio/clone_endio: 

Oct 13 03:16:54 10.80.5.48 Call Trace:
Oct 13 03:16:54 10.80.5.48 <NMI>
Oct 13 03:16:54 10.80.5.48 [<ffffffff81651631>] dump_stack+0x58/0x7f
Oct 13 03:16:54 10.80.5.48 [<ffffffff81089a6c>] warn_slowpath_common+0x8c/0xc0
Oct 13 03:16:54 10.80.5.48 [<ffffffff81089b56>] warn_slowpath_fmt+0x46/0x50
Oct 13 03:16:54 10.80.5.48 [<ffffffff811015f8>] watchdog_overflow_callback+0x98/0xc0
Oct 13 03:16:54 10.80.5.48 [<ffffffff81132d0c>] __perf_event_overflow+0x9c/0x250
Oct 13 03:16:54 10.80.5.48 [<ffffffff81133664>] perf_event_overflow+0x14/0x20
Oct 13 03:16:54 10.80.5.48 [<ffffffff81061796>] intel_pmu_handle_irq+0x1d6/0x3e0
Oct 13 03:16:54 10.80.5.48 [<ffffffff8105b4c4>] perf_event_nmi_handler+0x34/0x60
Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c152>] nmi_handle+0xa2/0x1a0
Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c3b4>] do_nmi+0x164/0x430
Oct 13 03:16:54 10.80.5.48 [<ffffffff81656e2e>] end_repeat_nmi+0x1a/0x1e
Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
Oct 13 03:16:54 10.80.5.48 <<EOE>> 
Oct 13 03:16:54 10.80.5.48 <IRQ> 
Oct 13 03:16:54 10.80.5.48 [<ffffffff8125c2c8>] ext4_end_bio+0xc8/0x120
Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
Oct 13 03:16:54 10.80.5.48 [<ffffffff812fad2b>] blk_update_request+0x21b/0x450
Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7797>] ? generic_exec_single+0xa7/0xb0
Oct 13 03:16:54 10.80.5.48 [<ffffffff812faf87>] blk_update_bidi_request+0x27/0xb0
Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7817>] ? __smp_call_function_single+0x77/0x120
Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcc7f>] blk_end_bidi_request+0x2f/0x80
Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcd20>] blk_end_request+0x10/0x20
Oct 13 03:16:54 10.80.5.48 [<ffffffff813fdc1c>] scsi_io_completion+0xbc/0x620
Oct 13 03:16:54 10.80.5.48 [<ffffffff813f57f9>] scsi_finish_command+0xc9/0x130
Oct 13 03:16:54 10.80.5.48 [<ffffffff813fe2e7>] scsi_softirq_done+0x147/0x170
Oct 13 03:16:54 10.80.5.48 [<ffffffff813035ad>] blk_done_softirq+0x7d/0x90
Oct 13 03:16:54 10.80.5.48 [<ffffffff8108ed87>] __do_softirq+0x137/0x2e0
Oct 13 03:16:54 10.80.5.48 [<ffffffff81658a0c>] call_softirq+0x1c/0x30
Oct 13 03:16:54 10.80.5.48 [<ffffffff8104a35d>] do_softirq+0x8d/0xc0
Oct 13 03:16:54 10.80.5.48 [<ffffffff8108e925>] irq_exit+0x95/0xa0
Oct 13 03:16:54 10.80.5.48 [<ffffffff81658f76>] do_IRQ+0x66/0xe0
Oct 13 03:16:54 10.80.5.48 [<ffffffff816567ef>] common_interrupt+0x6f/0x6f
Oct 13 03:16:54 10.80.5.48 <EOI> 
Oct 13 03:16:54 10.80.5.48 [<ffffffff81656836>] ? retint_swapgs+0xe/0x13
Oct 13 03:16:54 10.80.5.48 ---[ end trace 4a0584a583c66b92 ]---

Doing addr2line on ffffffff8125c2c8 shows: /home/projects/linux-stable/fs/ext4/page-io.c:335
which for me is the last bio_put in ext4_end_bio. However, the ? addresses, 
right at the beginning of the NMI stack (ffffffff8125be19) map to inner loop in
bit_spin_lock:

} while (test_bit(bitnum, addr));

and this is in line with my initial bug report. 

Unfortunately I wasn't able to acquire a crashdump since the machine hard-locked
way too fast. On a slightly different note is it possible to panic the machine 
via NMIs? Since if all the CPUs are hard lockedup they cannot process sysrq interrupts?

> 
>> Btw I think in any case the spin_lock patch is wrong as this code can be
>> called from within softirq context and we do want to be interrupt safe
>> at that point.
> 
> Agreed, that patch is definitely wrong.
> 
>>> BTW: I suppose the filesystem uses 4k blocksize, doesn't it?
>>
>> Unfortunately I cannot tell you with 100% certainty, since on this
>> server there are multiple block devices with blocksize either 1k or 4k.
>> So it is one of these. If you know a way to extract this information
>> from a vmcore file I'd be happy to do it.
> 
> Well, if you have a crashdump, then bh->b_size is the block size. So just
> check that for the bh we are spinning on.

Turns out in my original email the bh->b_size was shown : 
b_size = 0x400 == 1k. So the filesystem is not 4k but 1k. 


> 
> 								Honza
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1245693 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

FromJan Kara <jack@suse.cz>
Date2015-10-13 15:20 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qj7EJ-7EQ-1@gated-at.bofh.it>
In reply to#1245561

[Multipart message — attachments visible in raw view] — view raw

On Tue 13-10-15 13:37:16, Nikolay Borisov wrote:
> 
> 
> On 10/13/2015 11:15 AM, Jan Kara wrote:
> > On Mon 12-10-15 17:51:07, Nikolay Borisov wrote:
> >> Hello and thanks for the reply,
> >>
> >> On 10/12/2015 04:40 PM, Jan Kara wrote:
> >>> On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
> >>>> On 10/09/2015 10:37 AM, Hillf Danton wrote:
> >>>>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
> >>>>>>>>  			if (bio->bi_error)
> >>>>>>>>  				buffer_io_error(bh);
> >>>>>>>>  		} while ((bh = bh->b_this_page) != head);
> >>>>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
> >>>>>>>>  		local_irq_restore(flags);
> >>>>>>>
> >>>>>>> What if it takes 100ms to unlock after IRQ restored?
> >>>>>>
> >>>>>> I'm not sure I understand in what direction you are going? Care to
> >>>>>> elaborate?
> >>>>>>
> >>>>> Your change introduces extra time cost the lock waiter has to pay in
> >>>>> the case that irq happens before the lock is released.
> >>>>
> >>>> [CC filesystem and mm people. For reference the thread starts here:
> >>>>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
> >>>>
> >>>> Right, I see what you mean and it's a good point but when doing the
> >>>> patches I was striving for correctness and starting a discussion, hence
> >>>> the RFC. In any case I'd personally choose correctness over performance
> >>>> always ;).
> >>>>
> >>>> As I'm not an fs/ext4 expert and have added the relevant parties (please
> >>>> use reply-all from now on so that the thread is not being cut in the
> >>>> middle) who will be able to say whether it impact is going to be that
> >>>> big. I guess in this particular code path worrying about this is prudent
> >>>> as writeback sounds like a heavily used path.
> >>>>
> >>>> Maybe the problem should be approached from a different angle e.g.
> >>>> drain_all_pages and its reliance on the fact that the IPI will always be
> >>>> delivered in some finite amount of time? But what if a cpu with disabled
> >>>> interrupts is waiting on the task issuing the IPI?
> >>>
> >>> So I have looked through your patch and also original report (thread starts
> >>> here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
> >>> been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
> >>> on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
> >>> __block_write_full_page_endio() call but that cannot really be the case.
> >>> BH_Uptodate_Lock is used only in IO completion handlers -
> >>> end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
> >>> really should be some end_io function running on some other CPU which holds
> >>> BH_Uptodate_Lock for that buffer.
> >>
> >> I did check all the call traces of the current processes on the machine
> >> at the time of the hard lockup and none of the 3 functions you mentioned
> >> were in any of the call chains. But while I was looking the code of
> >> end_buffer_async_write and in the comments I saw it was mentioned that
> >> those completion handler were called from __block_write_full_page_endio
> >> so that's what pointed my attention to that function. But you are right
> >> that it doesn't take the BH lock.
> >>
> >> Furthermore the fact that the BH_Async_Write flag is set points me in
> >> the direction that end_buffer_async_write should have been executing but
> >> as I said issuing "bt" for all the tasks didn't show this function.
> > 
> > Actually ext4_bio_write_page() also sets BH_Async_Write so that seems like
> > a more likely place where that flag got set since ext4_finish_bio() was
> > then handling IO completion.
> > 
> >> I'm beginning to wonder if it's possible that a single bit memory error
> >> has crept up, but this still seems like a long shot...
> > 
> > Yup. Possible but a long shot. Is the problem reproducible in any way?
> 
> Okay, I rule out hardware issue since a different server today 
> experienced the same hard lockup. One thing which looks 
> suspicious to me are the repetitions of bio_endio/clone_endio: 
> 
> Oct 13 03:16:54 10.80.5.48 Call Trace:
> Oct 13 03:16:54 10.80.5.48 <NMI>
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81651631>] dump_stack+0x58/0x7f
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089a6c>] warn_slowpath_common+0x8c/0xc0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089b56>] warn_slowpath_fmt+0x46/0x50
> Oct 13 03:16:54 10.80.5.48 [<ffffffff811015f8>] watchdog_overflow_callback+0x98/0xc0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81132d0c>] __perf_event_overflow+0x9c/0x250
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81133664>] perf_event_overflow+0x14/0x20
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81061796>] intel_pmu_handle_irq+0x1d6/0x3e0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8105b4c4>] perf_event_nmi_handler+0x34/0x60
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c152>] nmi_handle+0xa2/0x1a0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c3b4>] do_nmi+0x164/0x430
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656e2e>] end_repeat_nmi+0x1a/0x1e
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
> Oct 13 03:16:54 10.80.5.48 <<EOE>> 
> Oct 13 03:16:54 10.80.5.48 <IRQ> 
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125c2c8>] ext4_end_bio+0xc8/0x120
> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fad2b>] blk_update_request+0x21b/0x450
> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7797>] ? generic_exec_single+0xa7/0xb0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff812faf87>] blk_update_bidi_request+0x27/0xb0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7817>] ? __smp_call_function_single+0x77/0x120
> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcc7f>] blk_end_bidi_request+0x2f/0x80
> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcd20>] blk_end_request+0x10/0x20
> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fdc1c>] scsi_io_completion+0xbc/0x620
> Oct 13 03:16:54 10.80.5.48 [<ffffffff813f57f9>] scsi_finish_command+0xc9/0x130
> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fe2e7>] scsi_softirq_done+0x147/0x170
> Oct 13 03:16:54 10.80.5.48 [<ffffffff813035ad>] blk_done_softirq+0x7d/0x90
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108ed87>] __do_softirq+0x137/0x2e0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658a0c>] call_softirq+0x1c/0x30
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104a35d>] do_softirq+0x8d/0xc0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108e925>] irq_exit+0x95/0xa0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658f76>] do_IRQ+0x66/0xe0
> Oct 13 03:16:54 10.80.5.48 [<ffffffff816567ef>] common_interrupt+0x6f/0x6f
> Oct 13 03:16:54 10.80.5.48 <EOI> 
> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656836>] ? retint_swapgs+0xe/0x13
> Oct 13 03:16:54 10.80.5.48 ---[ end trace 4a0584a583c66b92 ]---
> 
> Doing addr2line on ffffffff8125c2c8 shows:
> /home/projects/linux-stable/fs/ext4/page-io.c:335 which for me is the
> last bio_put in ext4_end_bio. However, the ? addresses, right at the
> beginning of the NMI stack (ffffffff8125be19) map to inner loop in
> bit_spin_lock:
> 
> } while (test_bit(bitnum, addr));
> 
> and this is in line with my initial bug report. 

OK.

> Unfortunately I wasn't able to acquire a crashdump since the machine
> hard-locked way too fast.
>
> On a slightly different note is it possible to
> panic the machine via NMIs? Since if all the CPUs are hard lockedup they
> cannot process sysrq interrupts?

Certainly it's possible to do that - the easiest way is actually to use

nmi_watchdog=panic

Then panic will automatically trigger when watchdog fires.

> >> Btw I think in any case the spin_lock patch is wrong as this code can be
> >> called from within softirq context and we do want to be interrupt safe
> >> at that point.
> > 
> > Agreed, that patch is definitely wrong.
> > 
> >>> BTW: I suppose the filesystem uses 4k blocksize, doesn't it?
> >>
> >> Unfortunately I cannot tell you with 100% certainty, since on this
> >> server there are multiple block devices with blocksize either 1k or 4k.
> >> So it is one of these. If you know a way to extract this information
> >> from a vmcore file I'd be happy to do it.
> > 
> > Well, if you have a crashdump, then bh->b_size is the block size. So just
> > check that for the bh we are spinning on.
> 
> Turns out in my original email the bh->b_size was shown : 
> b_size = 0x400 == 1k. So the filesystem is not 4k but 1k. 

OK, then I have a theory. We can manipulate bh->b_state in a non-atomic
manner in _ext4_get_block(). If we happen to do that on the first buffer in
a page while IO completes on another buffer in the same page, we could in
theory mess up and miss clearing of BH_Uptodate_Lock flag. Can you try
whether the attached patch fixes your problem?

								Honza

-- 
Jan Kara <jack@suse.com>
SUSE Labs, CR

[toc] | [prev] | [next] | [standalone]

#1246433

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-14 11:10 +0200
Message-ID<qjqem-2hl-9@gated-at.bofh.it>
In reply to#1245693

On 10/13/2015 04:14 PM, Jan Kara wrote:
> On Tue 13-10-15 13:37:16, Nikolay Borisov wrote:
>>
>>
>> On 10/13/2015 11:15 AM, Jan Kara wrote:
>>> On Mon 12-10-15 17:51:07, Nikolay Borisov wrote:
>>>> Hello and thanks for the reply,
>>>>
>>>> On 10/12/2015 04:40 PM, Jan Kara wrote:
>>>>> On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
>>>>>> On 10/09/2015 10:37 AM, Hillf Danton wrote:
>>>>>>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>>>>>>>>>  			if (bio->bi_error)
>>>>>>>>>>  				buffer_io_error(bh);
>>>>>>>>>>  		} while ((bh = bh->b_this_page) != head);
>>>>>>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>>>>>>>  		local_irq_restore(flags);
>>>>>>>>>
>>>>>>>>> What if it takes 100ms to unlock after IRQ restored?
>>>>>>>>
>>>>>>>> I'm not sure I understand in what direction you are going? Care to
>>>>>>>> elaborate?
>>>>>>>>
>>>>>>> Your change introduces extra time cost the lock waiter has to pay in
>>>>>>> the case that irq happens before the lock is released.
>>>>>>
>>>>>> [CC filesystem and mm people. For reference the thread starts here:
>>>>>>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
>>>>>>
>>>>>> Right, I see what you mean and it's a good point but when doing the
>>>>>> patches I was striving for correctness and starting a discussion, hence
>>>>>> the RFC. In any case I'd personally choose correctness over performance
>>>>>> always ;).
>>>>>>
>>>>>> As I'm not an fs/ext4 expert and have added the relevant parties (please
>>>>>> use reply-all from now on so that the thread is not being cut in the
>>>>>> middle) who will be able to say whether it impact is going to be that
>>>>>> big. I guess in this particular code path worrying about this is prudent
>>>>>> as writeback sounds like a heavily used path.
>>>>>>
>>>>>> Maybe the problem should be approached from a different angle e.g.
>>>>>> drain_all_pages and its reliance on the fact that the IPI will always be
>>>>>> delivered in some finite amount of time? But what if a cpu with disabled
>>>>>> interrupts is waiting on the task issuing the IPI?
>>>>>
>>>>> So I have looked through your patch and also original report (thread starts
>>>>> here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
>>>>> been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
>>>>> on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
>>>>> __block_write_full_page_endio() call but that cannot really be the case.
>>>>> BH_Uptodate_Lock is used only in IO completion handlers -
>>>>> end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
>>>>> really should be some end_io function running on some other CPU which holds
>>>>> BH_Uptodate_Lock for that buffer.
>>>>
>>>> I did check all the call traces of the current processes on the machine
>>>> at the time of the hard lockup and none of the 3 functions you mentioned
>>>> were in any of the call chains. But while I was looking the code of
>>>> end_buffer_async_write and in the comments I saw it was mentioned that
>>>> those completion handler were called from __block_write_full_page_endio
>>>> so that's what pointed my attention to that function. But you are right
>>>> that it doesn't take the BH lock.
>>>>
>>>> Furthermore the fact that the BH_Async_Write flag is set points me in
>>>> the direction that end_buffer_async_write should have been executing but
>>>> as I said issuing "bt" for all the tasks didn't show this function.
>>>
>>> Actually ext4_bio_write_page() also sets BH_Async_Write so that seems like
>>> a more likely place where that flag got set since ext4_finish_bio() was
>>> then handling IO completion.
>>>
>>>> I'm beginning to wonder if it's possible that a single bit memory error
>>>> has crept up, but this still seems like a long shot...
>>>
>>> Yup. Possible but a long shot. Is the problem reproducible in any way?
>>
>> Okay, I rule out hardware issue since a different server today 
>> experienced the same hard lockup. One thing which looks 
>> suspicious to me are the repetitions of bio_endio/clone_endio: 
>>
>> Oct 13 03:16:54 10.80.5.48 Call Trace:
>> Oct 13 03:16:54 10.80.5.48 <NMI>
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81651631>] dump_stack+0x58/0x7f
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089a6c>] warn_slowpath_common+0x8c/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089b56>] warn_slowpath_fmt+0x46/0x50
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811015f8>] watchdog_overflow_callback+0x98/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81132d0c>] __perf_event_overflow+0x9c/0x250
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81133664>] perf_event_overflow+0x14/0x20
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81061796>] intel_pmu_handle_irq+0x1d6/0x3e0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8105b4c4>] perf_event_nmi_handler+0x34/0x60
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c152>] nmi_handle+0xa2/0x1a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c3b4>] do_nmi+0x164/0x430
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656e2e>] end_repeat_nmi+0x1a/0x1e
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 <<EOE>> 
>> Oct 13 03:16:54 10.80.5.48 <IRQ> 
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125c2c8>] ext4_end_bio+0xc8/0x120
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fad2b>] blk_update_request+0x21b/0x450
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7797>] ? generic_exec_single+0xa7/0xb0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812faf87>] blk_update_bidi_request+0x27/0xb0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7817>] ? __smp_call_function_single+0x77/0x120
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcc7f>] blk_end_bidi_request+0x2f/0x80
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcd20>] blk_end_request+0x10/0x20
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fdc1c>] scsi_io_completion+0xbc/0x620
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813f57f9>] scsi_finish_command+0xc9/0x130
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fe2e7>] scsi_softirq_done+0x147/0x170
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813035ad>] blk_done_softirq+0x7d/0x90
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108ed87>] __do_softirq+0x137/0x2e0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658a0c>] call_softirq+0x1c/0x30
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104a35d>] do_softirq+0x8d/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108e925>] irq_exit+0x95/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658f76>] do_IRQ+0x66/0xe0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff816567ef>] common_interrupt+0x6f/0x6f
>> Oct 13 03:16:54 10.80.5.48 <EOI> 
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656836>] ? retint_swapgs+0xe/0x13
>> Oct 13 03:16:54 10.80.5.48 ---[ end trace 4a0584a583c66b92 ]---
>>
>> Doing addr2line on ffffffff8125c2c8 shows:
>> /home/projects/linux-stable/fs/ext4/page-io.c:335 which for me is the
>> last bio_put in ext4_end_bio. However, the ? addresses, right at the
>> beginning of the NMI stack (ffffffff8125be19) map to inner loop in
>> bit_spin_lock:
>>
>> } while (test_bit(bitnum, addr));
>>
>> and this is in line with my initial bug report. 
> 
> OK.
> 
>> Unfortunately I wasn't able to acquire a crashdump since the machine
>> hard-locked way too fast.
>>
>> On a slightly different note is it possible to
>> panic the machine via NMIs? Since if all the CPUs are hard lockedup they
>> cannot process sysrq interrupts?
> 
> Certainly it's possible to do that - the easiest way is actually to use
> 
> nmi_watchdog=panic
> 
> Then panic will automatically trigger when watchdog fires.
> 
>>>> Btw I think in any case the spin_lock patch is wrong as this code can be
>>>> called from within softirq context and we do want to be interrupt safe
>>>> at that point.
>>>
>>> Agreed, that patch is definitely wrong.
>>>
>>>>> BTW: I suppose the filesystem uses 4k blocksize, doesn't it?
>>>>
>>>> Unfortunately I cannot tell you with 100% certainty, since on this
>>>> server there are multiple block devices with blocksize either 1k or 4k.
>>>> So it is one of these. If you know a way to extract this information
>>>> from a vmcore file I'd be happy to do it.
>>>
>>> Well, if you have a crashdump, then bh->b_size is the block size. So just
>>> check that for the bh we are spinning on.
>>
>> Turns out in my original email the bh->b_size was shown : 
>> b_size = 0x400 == 1k. So the filesystem is not 4k but 1k. 
> 
> OK, then I have a theory. We can manipulate bh->b_state in a non-atomic
> manner in _ext4_get_block(). If we happen to do that on the first buffer in
> a page while IO completes on another buffer in the same page, we could in
> theory mess up and miss clearing of BH_Uptodate_Lock flag. Can you try
> whether the attached patch fixes your problem?

I will try the patch, however it might take some time to report back
since scheduling reboots on the live servers is going to be tricky and
unfortunately at the moment I cannot reproduce the issue on demand.


> 
> 								Honza
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1248449

FromNikolay Borisov <kernel@kyup.com>
Date2015-10-16 10:10 +0200
Message-ID<qk8fo-hv-15@gated-at.bofh.it>
In reply to#1245693

On 10/13/2015 04:14 PM, Jan Kara wrote:
> On Tue 13-10-15 13:37:16, Nikolay Borisov wrote:
>>
>>
>> On 10/13/2015 11:15 AM, Jan Kara wrote:
>>> On Mon 12-10-15 17:51:07, Nikolay Borisov wrote:
>>>> Hello and thanks for the reply,
>>>>
>>>> On 10/12/2015 04:40 PM, Jan Kara wrote:
>>>>> On Fri 09-10-15 11:03:30, Nikolay Borisov wrote:
>>>>>> On 10/09/2015 10:37 AM, Hillf Danton wrote:
>>>>>>>>>> @@ -109,8 +109,8 @@ static void ext4_finish_bio(struct bio *bio)
>>>>>>>>>>  			if (bio->bi_error)
>>>>>>>>>>  				buffer_io_error(bh);
>>>>>>>>>>  		} while ((bh = bh->b_this_page) != head);
>>>>>>>>>> -		bit_spin_unlock(BH_Uptodate_Lock, &head->b_state);
>>>>>>>>>>  		local_irq_restore(flags);
>>>>>>>>>
>>>>>>>>> What if it takes 100ms to unlock after IRQ restored?
>>>>>>>>
>>>>>>>> I'm not sure I understand in what direction you are going? Care to
>>>>>>>> elaborate?
>>>>>>>>
>>>>>>> Your change introduces extra time cost the lock waiter has to pay in
>>>>>>> the case that irq happens before the lock is released.
>>>>>>
>>>>>> [CC filesystem and mm people. For reference the thread starts here:
>>>>>>  http://thread.gmane.org/gmane.linux.kernel/2056996 ]
>>>>>>
>>>>>> Right, I see what you mean and it's a good point but when doing the
>>>>>> patches I was striving for correctness and starting a discussion, hence
>>>>>> the RFC. In any case I'd personally choose correctness over performance
>>>>>> always ;).
>>>>>>
>>>>>> As I'm not an fs/ext4 expert and have added the relevant parties (please
>>>>>> use reply-all from now on so that the thread is not being cut in the
>>>>>> middle) who will be able to say whether it impact is going to be that
>>>>>> big. I guess in this particular code path worrying about this is prudent
>>>>>> as writeback sounds like a heavily used path.
>>>>>>
>>>>>> Maybe the problem should be approached from a different angle e.g.
>>>>>> drain_all_pages and its reliance on the fact that the IPI will always be
>>>>>> delivered in some finite amount of time? But what if a cpu with disabled
>>>>>> interrupts is waiting on the task issuing the IPI?
>>>>>
>>>>> So I have looked through your patch and also original report (thread starts
>>>>> here: https://lkml.org/lkml/2015/10/8/341) and IMHO one question hasn't
>>>>> been properly answered yet: Who is holding BH_Uptodate_Lock we are spinning
>>>>> on? You have suggested in https://lkml.org/lkml/2015/10/8/464 that it was
>>>>> __block_write_full_page_endio() call but that cannot really be the case.
>>>>> BH_Uptodate_Lock is used only in IO completion handlers -
>>>>> end_buffer_async_read, end_buffer_async_write, ext4_finish_bio. So there
>>>>> really should be some end_io function running on some other CPU which holds
>>>>> BH_Uptodate_Lock for that buffer.
>>>>
>>>> I did check all the call traces of the current processes on the machine
>>>> at the time of the hard lockup and none of the 3 functions you mentioned
>>>> were in any of the call chains. But while I was looking the code of
>>>> end_buffer_async_write and in the comments I saw it was mentioned that
>>>> those completion handler were called from __block_write_full_page_endio
>>>> so that's what pointed my attention to that function. But you are right
>>>> that it doesn't take the BH lock.
>>>>
>>>> Furthermore the fact that the BH_Async_Write flag is set points me in
>>>> the direction that end_buffer_async_write should have been executing but
>>>> as I said issuing "bt" for all the tasks didn't show this function.
>>>
>>> Actually ext4_bio_write_page() also sets BH_Async_Write so that seems like
>>> a more likely place where that flag got set since ext4_finish_bio() was
>>> then handling IO completion.
>>>
>>>> I'm beginning to wonder if it's possible that a single bit memory error
>>>> has crept up, but this still seems like a long shot...
>>>
>>> Yup. Possible but a long shot. Is the problem reproducible in any way?
>>
>> Okay, I rule out hardware issue since a different server today 
>> experienced the same hard lockup. One thing which looks 
>> suspicious to me are the repetitions of bio_endio/clone_endio: 
>>
>> Oct 13 03:16:54 10.80.5.48 Call Trace:
>> Oct 13 03:16:54 10.80.5.48 <NMI>
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81651631>] dump_stack+0x58/0x7f
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089a6c>] warn_slowpath_common+0x8c/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81089b56>] warn_slowpath_fmt+0x46/0x50
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811015f8>] watchdog_overflow_callback+0x98/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81132d0c>] __perf_event_overflow+0x9c/0x250
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81133664>] perf_event_overflow+0x14/0x20
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81061796>] intel_pmu_handle_irq+0x1d6/0x3e0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8105b4c4>] perf_event_nmi_handler+0x34/0x60
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c152>] nmi_handle+0xa2/0x1a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104c3b4>] do_nmi+0x164/0x430
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656e2e>] end_repeat_nmi+0x1a/0x1e
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125be19>] ? ext4_finish_bio+0x279/0x2a0
>> Oct 13 03:16:54 10.80.5.48 <<EOE>> 
>> Oct 13 03:16:54 10.80.5.48 <IRQ> 
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8125c2c8>] ext4_end_bio+0xc8/0x120
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546781>] dec_pending+0x1c1/0x360
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81546996>] clone_endio+0x76/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff811dbf1d>] bio_endio+0x1d/0x40
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fad2b>] blk_update_request+0x21b/0x450
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7797>] ? generic_exec_single+0xa7/0xb0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812faf87>] blk_update_bidi_request+0x27/0xb0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff810e7817>] ? __smp_call_function_single+0x77/0x120
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcc7f>] blk_end_bidi_request+0x2f/0x80
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff812fcd20>] blk_end_request+0x10/0x20
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fdc1c>] scsi_io_completion+0xbc/0x620
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813f57f9>] scsi_finish_command+0xc9/0x130
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813fe2e7>] scsi_softirq_done+0x147/0x170
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff813035ad>] blk_done_softirq+0x7d/0x90
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108ed87>] __do_softirq+0x137/0x2e0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658a0c>] call_softirq+0x1c/0x30
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8104a35d>] do_softirq+0x8d/0xc0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff8108e925>] irq_exit+0x95/0xa0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81658f76>] do_IRQ+0x66/0xe0
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff816567ef>] common_interrupt+0x6f/0x6f
>> Oct 13 03:16:54 10.80.5.48 <EOI> 
>> Oct 13 03:16:54 10.80.5.48 [<ffffffff81656836>] ? retint_swapgs+0xe/0x13
>> Oct 13 03:16:54 10.80.5.48 ---[ end trace 4a0584a583c66b92 ]---
>>
>> Doing addr2line on ffffffff8125c2c8 shows:
>> /home/projects/linux-stable/fs/ext4/page-io.c:335 which for me is the
>> last bio_put in ext4_end_bio. However, the ? addresses, right at the
>> beginning of the NMI stack (ffffffff8125be19) map to inner loop in
>> bit_spin_lock:
>>
>> } while (test_bit(bitnum, addr));
>>
>> and this is in line with my initial bug report. 
> 
> OK.
> 
>> Unfortunately I wasn't able to acquire a crashdump since the machine
>> hard-locked way too fast.
>>
>> On a slightly different note is it possible to
>> panic the machine via NMIs? Since if all the CPUs are hard lockedup they
>> cannot process sysrq interrupts?
> 
> Certainly it's possible to do that - the easiest way is actually to use
> 
> nmi_watchdog=panic
> 
> Then panic will automatically trigger when watchdog fires.
> 
>>>> Btw I think in any case the spin_lock patch is wrong as this code can be
>>>> called from within softirq context and we do want to be interrupt safe
>>>> at that point.
>>>
>>> Agreed, that patch is definitely wrong.
>>>
>>>>> BTW: I suppose the filesystem uses 4k blocksize, doesn't it?
>>>>
>>>> Unfortunately I cannot tell you with 100% certainty, since on this
>>>> server there are multiple block devices with blocksize either 1k or 4k.
>>>> So it is one of these. If you know a way to extract this information
>>>> from a vmcore file I'd be happy to do it.
>>>
>>> Well, if you have a crashdump, then bh->b_size is the block size. So just
>>> check that for the bh we are spinning on.
>>
>> Turns out in my original email the bh->b_size was shown : 
>> b_size = 0x400 == 1k. So the filesystem is not 4k but 1k. 
> 
> OK, then I have a theory. We can manipulate bh->b_state in a non-atomic
> manner in _ext4_get_block(). If we happen to do that on the first buffer in
> a page while IO completes on another buffer in the same page, we could in
> theory mess up and miss clearing of BH_Uptodate_Lock flag. Can you try
> whether the attached patch fixes your problem?

I just want to make sure I have fully understood the problem. So the way
I understand what you have said is that since the blocksize is 1k this
potentially means we might need up to 4 buffer heads to map everything
in a page. But as you mentioned the locking in ext4_finish_bio is done
only on the first buffer_head in this set of bh. At the same time in
_ext4_get_block bh->b_state is modified non-atomically as you said, and
this can happen in one of those 4bh used to map the whole page? Correct?

If my reasoning is correct then I see no reason why this corruption
couldn't happen even with blocksize == pagesize since ext4_get_block's
non-atomic modification of the bh->b_state could still race with
ext4_finish_bio's atomic modification (even though ext4_finish_bio would
just work on a single buffer head)?

Sorry if the question seems stupid but I just want to fully wrap my head
around the internals of it.

Thanks

> 
> 								Honza
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1248720 — Re: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI

FromJan Kara <jack@suse.cz>
Date2015-10-16 15:00 +0200
SubjectRe: [RFC PATCH 1/2] ext4: Fix possible deadlock with local interrupts disabled and page-draining IPI
Message-ID<qkcM3-6LS-25@gated-at.bofh.it>
In reply to#1248449
On Fri 16-10-15 11:08:46, Nikolay Borisov wrote:
> On 10/13/2015 04:14 PM, Jan Kara wrote:
> >> Turns out in my original email the bh->b_size was shown : 
> >> b_size = 0x400 == 1k. So the filesystem is not 4k but 1k. 
> > 
> > OK, then I have a theory. We can manipulate bh->b_state in a non-atomic
> > manner in _ext4_get_block(). If we happen to do that on the first buffer in
> > a page while IO completes on another buffer in the same page, we could in
> > theory mess up and miss clearing of BH_Uptodate_Lock flag. Can you try
> > whether the attached patch fixes your problem?
> 
> I just want to make sure I have fully understood the problem. So the way
> I understand what you have said is that since the blocksize is 1k this
> potentially means we might need up to 4 buffer heads to map everything
> in a page. But as you mentioned the locking in ext4_finish_bio is done
> only on the first buffer_head in this set of bh. At the same time in
> _ext4_get_block bh->b_state is modified non-atomically as you said, and
> this can happen in one of those 4bh used to map the whole page? Correct?
> 
> If my reasoning is correct then I see no reason why this corruption
> couldn't happen even with blocksize == pagesize since ext4_get_block's
> non-atomic modification of the bh->b_state could still race with
> ext4_finish_bio's atomic modification (even though ext4_finish_bio would
> just work on a single buffer head)?

Well, the reason why this race is not possible with 4k blocks is that we
map blocks in a page (i.e., call _ext4_get_block()) only under page lock
and only when the buffer isn't already mapped. And in such case IO
completion cannot happen (for IO to run buffer must be mapped). So it's
mostly a pure luck but the race is not possible...

								Honza
-- 
Jan Kara <jack@suse.com>
SUSE Labs, CR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web