Btrfs switches to using mostly one thread

Btrfs switches to using mostly one thread

[Jeremy Sanders]

Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4 
(Fedora 16, x86_64, dual-core), where after a few hours of writing, it 
switches from writing with several threads to writing with one:

After:

21996 root      20   0     0    0    0 R 97.2  0.0 109:03.57 btrfs-delalloc-
23332 root      20   0  137m  14m 1000 S  3.3  1.0   5:40.32 tar
23333 root      20   0  125m 3620  960 D  2.7  0.2   4:33.04 tar
22026 root      20   0     0    0    0 S  2.0  0.0   3:14.73 btrfs-endio-wri
23626 root      20   0     0    0    0 S  2.0  0.0   0:17.64 kworker/0:0
   55 root      20   0     0    0    0 S  1.3  0.0   6:46.35 kswapd0
22255 root      20   0     0    0    0 S  1.0  0.0   2:12.30 kworker/0:2
22025 root      20   0     0    0    0 S  0.3  0.0   3:16.34 btrfs-endio-wri

Before:

23867 root      20   0     0    0    0 R 66.6  0.0   0:13.45 btrfs-delalloc-
24021 root      20   0     0    0    0 R 60.6  0.0   0:10.58 btrfs-delalloc-
24025 root      20   0     0    0    0 R 45.7  0.0   0:10.01 btrfs-delalloc-
24018 root      20   0  124m 2384 1116 R  8.6  0.2   0:03.31 tar
24019 root      20   0  124m 2276 1052 S  7.0  0.1   0:02.47 tar
   55 root      20   0     0    0    0 S  2.6  0.0   6:47.92 kswapd0
24022 root      20   0     0    0    0 S  2.0  0.0   0:00.59 btrfs-endio-wri
22255 root      20   0     0    0    0 S  1.7  0.0   2:13.45 kworker/0:2
23626 root      20   0     0    0    0 S  1.7  0.0   0:18.84 kworker/0:0
24024 root      20   0     0    0    0 S  1.7  0.0   0:00.77 btrfs-endio-wri
23866 root      20   0     0    0    0 S  0.7  0.0   0:00.25 btrfs-submit-0
23912 root      20   0     0    0    0 D  0.3  0.0   0:00.26 flush-btrfs-4

It can be put back to its initial behaviour by unmounting and reloading the 
btrfs kernel module. I'm using compress-force=zlib for this, and it's 
writing with a tar-to-tar pipe (or rsync). I think switching to one thread 
it has a pretty negative impact on write speed (50%).

I think the cause is writing lots of small files to the disk, but I can't be 
sure.

Jeremy

Re: Btrfs switches to using mostly one thread

[Chris Mason]

On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4 
> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it 
> switches from writing with several threads to writing with one:

Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
like to see what the other delalloc-writers are doing.

-chris

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

On 08/12/11 15:32, Chris Mason wrote:
> On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
>> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
>> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it
>> switches from writing with several threads to writing with one:
>
> Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
> like to see what the other delalloc-writers are doing.

I'll restart the copying to get it back to its failed state and post the 
results when it fails.

Jeremy

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

[-- Attachment #1: Type: text/plain, Size: 554 bytes --]

On 08/12/11 15:32, Chris Mason wrote:
> On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
>> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
>> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it
>> switches from writing with several threads to writing with one:
>
> Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
> like to see what the other delalloc-writers are doing.

I've attached sysrq-t. It looks like it might be truncated at the 
beginning, however.

Jeremy

[-- Attachment #2: sysrq2.txt.gz --]
[-- Type: application/x-gzip, Size: 11466 bytes --]

Re: Btrfs switches to using mostly one thread

[Chris Mason]

On Thu, Dec 08, 2011 at 04:57:12PM +0000, Jeremy Sanders wrote:
> On 08/12/11 15:32, Chris Mason wrote:
> >On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
> >>Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
> >>(Fedora 16, x86_64, dual-core), where after a few hours of writing, it
> >>switches from writing with several threads to writing with one:
> >
> >Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
> >like to see what the other delalloc-writers are doing.
> 
> I've attached sysrq-t. It looks like it might be truncated at the
> beginning, however.

/var/log/messages may have the whole thing, please do check.

-chris

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

On 08/12/11 17:23, Chris Mason wrote:
> On Thu, Dec 08, 2011 at 04:57:12PM +0000, Jeremy Sanders wrote:
>> On 08/12/11 15:32, Chris Mason wrote:
>>> On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
>>>> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
>>>> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it
>>>> switches from writing with several threads to writing with one:
>>>
>>> Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
>>> like to see what the other delalloc-writers are doing.
>>
>> I've attached sysrq-t. It looks like it might be truncated at the
>> beginning, however.
>
> /var/log/messages may have the whole thing, please do check.

That was from /var/log/messages. I think it needs a longer log_buf_len. 
Unfortunately the system hasn't come back from its reboot, so it will 
have to wait until tomorrow when I can get to it physically.

Jeremy

Re: Btrfs switches to using mostly one thread

[Chris Mason]

On Thu, Dec 08, 2011 at 05:39:16PM +0000, Jeremy Sanders wrote:
> On 08/12/11 17:23, Chris Mason wrote:
> >On Thu, Dec 08, 2011 at 04:57:12PM +0000, Jeremy Sanders wrote:
> >>On 08/12/11 15:32, Chris Mason wrote:
> >>>On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
> >>>>Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
> >>>>(Fedora 16, x86_64, dual-core), where after a few hours of writing, it
> >>>>switches from writing with several threads to writing with one:
> >>>
> >>>Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
> >>>like to see what the other delalloc-writers are doing.
> >>
> >>I've attached sysrq-t. It looks like it might be truncated at the
> >>beginning, however.
> >
> >/var/log/messages may have the whole thing, please do check.
> 
> That was from /var/log/messages. I think it needs a longer
> log_buf_len. Unfortunately the system hasn't come back from its
> reboot, so it will have to wait until tomorrow when I can get to it
> physically.

Ok, this trace shows that we have tar sitting in balance_dirty_pages and
we have the single delalloc worker doing requests.  The other delalloc
workers don't show up at all.

So either they are earlier in the trace or they disappeared somehow.
I'll definitely need the full trace if you can send it.

-chris

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

On 08/12/11 20:11, Chris Mason wrote:
> On Thu, Dec 08, 2011 at 05:39:16PM +0000, Jeremy Sanders wrote:
>> On 08/12/11 17:23, Chris Mason wrote:
>>> On Thu, Dec 08, 2011 at 04:57:12PM +0000, Jeremy Sanders wrote:
>>>> On 08/12/11 15:32, Chris Mason wrote:
>>>>> On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
>>>>>> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
>>>>>> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it
>>>>>> switches from writing with several threads to writing with one:
>>>>>
>>>>> Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
>>>>> like to see what the other delalloc-writers are doing.
>>>>
>>>> I've attached sysrq-t. It looks like it might be truncated at the
>>>> beginning, however.
>>>
>>> /var/log/messages may have the whole thing, please do check.
>>
>> That was from /var/log/messages. I think it needs a longer
>> log_buf_len. Unfortunately the system hasn't come back from its
>> reboot, so it will have to wait until tomorrow when I can get to it
>> physically.
>
> Ok, this trace shows that we have tar sitting in balance_dirty_pages and
> we have the single delalloc worker doing requests.  The other delalloc
> workers don't show up at all.
>
> So either they are earlier in the trace or they disappeared somehow.
> I'll definitely need the full trace if you can send it.

I've got the full trace now. It's pretty big (430KB), so I've put it on 
the web.

Here's the state before switching to one thread
http://www-xray.ast.cam.ac.uk/~jss/data/btrfs-before.txt

Here it is after it has switched to one thread:
http://www-xray.ast.cam.ac.uk/~jss/data/btrfs-after.txt

Jeremy

Re: Btrfs switches to using mostly one thread

[Chris Mason]

On Fri, Dec 09, 2011 at 12:05:40PM +0000, Jeremy Sanders wrote:
> On 08/12/11 20:11, Chris Mason wrote:
> >On Thu, Dec 08, 2011 at 05:39:16PM +0000, Jeremy Sanders wrote:
> >>On 08/12/11 17:23, Chris Mason wrote:
> >>>On Thu, Dec 08, 2011 at 04:57:12PM +0000, Jeremy Sanders wrote:
> >>>>On 08/12/11 15:32, Chris Mason wrote:
> >>>>>On Thu, Dec 08, 2011 at 03:19:38PM +0000, Jeremy Sanders wrote:
> >>>>>>Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
> >>>>>>(Fedora 16, x86_64, dual-core), where after a few hours of writing, it
> >>>>>>switches from writing with several threads to writing with one:
> >>>>>
> >>>>>Ok, I'll try to reproduce this here.  Could you please do a sysrq-t, I'd
> >>>>>like to see what the other delalloc-writers are doing.
> >>>>
> >>>>I've attached sysrq-t. It looks like it might be truncated at the
> >>>>beginning, however.
> >>>
> >>>/var/log/messages may have the whole thing, please do check.
> >>
> >>That was from /var/log/messages. I think it needs a longer
> >>log_buf_len. Unfortunately the system hasn't come back from its
> >>reboot, so it will have to wait until tomorrow when I can get to it
> >>physically.
> >
> >Ok, this trace shows that we have tar sitting in balance_dirty_pages and
> >we have the single delalloc worker doing requests.  The other delalloc
> >workers don't show up at all.
> >
> >So either they are earlier in the trace or they disappeared somehow.
> >I'll definitely need the full trace if you can send it.
> 
> I've got the full trace now. It's pretty big (430KB), so I've put it
> on the web.
> 
> Here's the state before switching to one thread
> http://www-xray.ast.cam.ac.uk/~jss/data/btrfs-before.txt
> 
> Here it is after it has switched to one thread:
> http://www-xray.ast.cam.ac.uk/~jss/data/btrfs-after.txt

According to this you've only got one delalloc worker.  That would
explain it.  Could you please confirm with ps?

You might be hitting a problem Josef sent patches for, I'll dig in.

-chris

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

On 09/12/11 14:18, Chris Mason wrote:

> According to this you've only got one delalloc worker.  That would
> explain it.  Could you please confirm with ps?

Yes - only one delalloc worker is now present, but there were at least 
three initially.

Jeremy

Re: Btrfs switches to using mostly one thread

[Arne Jansen]

On 08.12.2011 16:19, Jeremy Sanders wrote:
> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4 
> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it 
> switches from writing with several threads to writing with one:

How many disks does the fs have?

-Arne

Re: Btrfs switches to using mostly one thread

[Jeremy Sanders]

On 09/12/11 12:15, Arne Jansen wrote:
> On 08.12.2011 16:19, Jeremy Sanders wrote:
>> Hi - I'm trying out btrfs again, and I see the same old bug in kernel 3.1.4
>> (Fedora 16, x86_64, dual-core), where after a few hours of writing, it
>> switches from writing with several threads to writing with one:
>
> How many disks does the fs have?

One - it's writing onto a "linear" MD array (for testing purposes). I 
disabled duplication of metadata as well, and zlib compression is forced.

Jeremy