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

Groups > linux.debian.kernel > #63439 > unrolled thread

Bug#908216: btrfs blocked for more than 120 seconds

Back to article view | Back to linux.debian.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

  Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-02-25 01:40 +0100
    Bug#908216: btrfs blocked for more than 120 seconds Nicholas D Steeves <nsteeves@gmail.com> - 2019-02-25 02:10 +0100
      Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-02-25 19:50 +0100
        Bug#908216: btrfs blocked for more than 120 seconds Nicholas D Steeves <nsteeves@gmail.com> - 2019-02-26 05:30 +0100
          Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-02-27 13:30 +0100
            Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-02-27 17:30 +0100
              Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-03-02 13:00 +0100
          Bug#908216: btrfs blocked for more than 120 seconds Nicholas D Steeves <nsteeves@gmail.com> - 2019-03-02 23:10 +0100
            Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-03-03 00:20 +0100
              Bug#908216: btrfs blocked for more than 120 seconds Nicholas D Steeves <nsteeves@gmail.com> - 2019-03-03 02:10 +0100
            Bug#908216: btrfs blocked for more than 120 seconds "Russell Mosemann" <rmosemann@futurefoam.com> - 2019-03-06 15:00 +0100
              Bug#908216: btrfs blocked for more than 120 seconds Nicholas D Steeves <nsteeves@gmail.com> - 2019-03-09 01:30 +0100

#63439 — Bug#908216: btrfs blocked for more than 120 seconds

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

 
Package: src:linux
Version: 4.19.16-1~bpo9+1
Severity: important
 
 
If the btrfs fixes will not be backported to 4.19, then this is not an appropriate base kernel for the next version of Debian.
 
 
Feb 24 19:09:21 vhost182 kernel: INFO: task btrfs-transacti:604 blocked for more than 120 seconds.
Feb 24 19:09:21 vhost182 kernel:       Not tainted 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
Feb 24 19:09:21 vhost182 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 24 19:09:21 vhost182 kernel: btrfs-transacti D    0   604      2 0x80000000
Feb 24 19:09:21 vhost182 kernel: Call Trace:
Feb 24 19:09:21 vhost182 kernel:  ? __schedule+0x3f5/0x880
Feb 24 19:09:21 vhost182 kernel:  schedule+0x32/0x80
Feb 24 19:09:21 vhost182 kernel:  btrfs_start_ordered_extent+0xed/0x120 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  ? remove_wait_queue+0x60/0x60
Feb 24 19:09:21 vhost182 kernel:  btrfs_wait_ordered_range+0xa0/0x100 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  __btrfs_wait_cache_io+0x46/0x1c0 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  btrfs_start_dirty_block_groups+0x1ad/0x4b0 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  btrfs_commit_transaction+0xc8/0x8a0 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  ? start_transaction+0x8f/0x3e0 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  transaction_kthread+0x157/0x180 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  kthread+0xf8/0x130
Feb 24 19:09:21 vhost182 kernel:  ? btrfs_cleanup_transaction+0x500/0x500 [btrfs]
Feb 24 19:09:21 vhost182 kernel:  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 24 19:09:21 vhost182 kernel:  ret_from_fork+0x35/0x40

Feb 24 19:11:22 vhost182 kernel: INFO: task btrfs-transacti:604 blocked for more than 120 seconds.
Feb 24 19:11:22 vhost182 kernel:       Not tainted 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
Feb 24 19:11:22 vhost182 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 24 19:11:22 vhost182 kernel: btrfs-transacti D    0   604      2 0x80000000
Feb 24 19:11:22 vhost182 kernel: Call Trace:
Feb 24 19:11:22 vhost182 kernel:  ? __schedule+0x3f5/0x880
Feb 24 19:11:22 vhost182 kernel:  schedule+0x32/0x80
Feb 24 19:11:22 vhost182 kernel:  btrfs_start_ordered_extent+0xed/0x120 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  ? remove_wait_queue+0x60/0x60
Feb 24 19:11:22 vhost182 kernel:  btrfs_wait_ordered_range+0xa0/0x100 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  __btrfs_wait_cache_io+0x46/0x1c0 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  btrfs_start_dirty_block_groups+0x1ad/0x4b0 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  btrfs_commit_transaction+0xc8/0x8a0 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  ? start_transaction+0x8f/0x3e0 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  transaction_kthread+0x157/0x180 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  kthread+0xf8/0x130
Feb 24 19:11:22 vhost182 kernel:  ? btrfs_cleanup_transaction+0x500/0x500 [btrfs]
Feb 24 19:11:22 vhost182 kernel:  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 24 19:11:22 vhost182 kernel:  ret_from_fork+0x35/0x40
Feb 24 19:13:23 vhost182 kernel: INFO: task btrfs-transacti:604 blocked for more than 120 seconds.
Feb 24 19:13:23 vhost182 kernel:       Not tainted 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
Feb 24 19:13:23 vhost182 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 24 19:13:23 vhost182 kernel: btrfs-transacti D    0   604      2 0x80000000
Feb 24 19:13:23 vhost182 kernel: Call Trace:
Feb 24 19:13:23 vhost182 kernel:  ? __schedule+0x3f5/0x880
Feb 24 19:13:23 vhost182 kernel:  schedule+0x32/0x80
Feb 24 19:13:23 vhost182 kernel:  btrfs_start_ordered_extent+0xed/0x120 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  ? remove_wait_queue+0x60/0x60
Feb 24 19:13:23 vhost182 kernel:  btrfs_wait_ordered_range+0xa0/0x100 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  __btrfs_wait_cache_io+0x46/0x1c0 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  btrfs_start_dirty_block_groups+0x1ad/0x4b0 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  btrfs_commit_transaction+0xc8/0x8a0 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  ? start_transaction+0x8f/0x3e0 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  transaction_kthread+0x157/0x180 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  kthread+0xf8/0x130
Feb 24 19:13:23 vhost182 kernel:  ? btrfs_cleanup_transaction+0x500/0x500 [btrfs]
Feb 24 19:13:23 vhost182 kernel:  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 24 19:13:23 vhost182 kernel:  ret_from_fork+0x35/0x40

Feb 24 19:15:24 vhost182 kernel: INFO: task btrfs-transacti:604 blocked for more than 120 seconds.
Feb 24 19:15:24 vhost182 kernel:       Not tainted 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
Feb 24 19:15:24 vhost182 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 24 19:15:24 vhost182 kernel: btrfs-transacti D    0   604      2 0x80000000
Feb 24 19:15:24 vhost182 kernel: Call Trace:
Feb 24 19:15:24 vhost182 kernel:  ? __schedule+0x3f5/0x880
Feb 24 19:15:24 vhost182 kernel:  schedule+0x32/0x80
Feb 24 19:15:25 vhost182 kernel:  btrfs_start_ordered_extent+0xed/0x120 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  ? remove_wait_queue+0x60/0x60
Feb 24 19:15:25 vhost182 kernel:  btrfs_wait_ordered_range+0xa0/0x100 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  __btrfs_wait_cache_io+0x46/0x1c0 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  btrfs_start_dirty_block_groups+0x1ad/0x4b0 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  btrfs_commit_transaction+0xc8/0x8a0 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  ? start_transaction+0x8f/0x3e0 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  transaction_kthread+0x157/0x180 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  kthread+0xf8/0x130
Feb 24 19:15:25 vhost182 kernel:  ? btrfs_cleanup_transaction+0x500/0x500 [btrfs]
Feb 24 19:15:25 vhost182 kernel:  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 24 19:15:25 vhost182 kernel:  ret_from_fork+0x35/0x40

Feb 24 19:17:25 vhost182 kernel: INFO: task btrfs-transacti:604 blocked for more than 120 seconds.
Feb 24 19:17:26 vhost182 kernel:       Not tainted 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
Feb 24 19:17:29 vhost182 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 24 19:17:30 vhost182 kernel: btrfs-transacti D    0   604      2 0x80000000
Feb 24 19:17:30 vhost182 kernel: Call Trace:
Feb 24 19:17:31 vhost182 kernel:  ? __schedule+0x3f5/0x880
Feb 24 19:17:31 vhost182 kernel:  schedule+0x32/0x80
Feb 24 19:17:31 vhost182 kernel:  btrfs_start_ordered_extent+0xed/0x120 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  ? remove_wait_queue+0x60/0x60
Feb 24 19:17:31 vhost182 kernel:  btrfs_wait_ordered_range+0xa0/0x100 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  __btrfs_wait_cache_io+0x46/0x1c0 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  btrfs_start_dirty_block_groups+0x1ad/0x4b0 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  btrfs_commit_transaction+0xc8/0x8a0 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  ? start_transaction+0x8f/0x3e0 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  transaction_kthread+0x157/0x180 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  kthread+0xf8/0x130
Feb 24 19:17:31 vhost182 kernel:  ? btrfs_cleanup_transaction+0x500/0x500 [btrfs]
Feb 24 19:17:31 vhost182 kernel:  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 24 19:17:31 vhost182 kernel:  ret_from_fork+0x35/0x40

 

[toc] | [next] | [standalone]

#63441

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

Control: tags -1 + unreproducible moreinfo

Hi Russell,

On Sun, Feb 24, 2019 at 06:34:59PM -0600, Russell Mosemann wrote:
>     
> 
>    Package: src:linux
>    Version: 4.19.16-1~bpo9+1
>    Severity: important
> 
>     
> 
>     
> 
>    If the btrfs fixes will not be backported to 4.19, then this is not an
>    appropriate base kernel for the next version of Debian.
> 

Please provide steps to reproduce, including but not limited to:
whether or not you are using qgroups, compression, the number of
snapshots and subvolumes, 'grep btrfs /etc/mtab', what raid profile
you're using (if any), along with the output of 'sudo smartctl -l
scterc /dev/each_disk_in_the_volume', if you're using bcache, if the
devices are layered on top of md or lvm, 'btrfs dev stats $volume'...

Additional dmesg output is not useful.

Sincerely,
Nicholas

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

#63444

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

Steps to reproduce

Simply copying a file into the file system can cause things to lock up. In this case, the files will usually be thin-provisioned qcow2 disks for kvm vm's. There is no detailed formula to force the lockup to occur, but it happens regularly, sometimes multiple times in one day.
 
Files are often copied from a master by reference (cp --reflink), one per day to perform a daily backup for up to 45 days. Removing older files is a painfully slow process, even though there are only 45 files in the directory. Doing a scrub is almost a sure way to lock up the system, especially if a copy or delete operation is in progress. On two systems, crashes occur with 4.18 and 4.19 but not 4.17. On the other systems that crash, it does not seem to matter if it is 4.17, 4.18 or 4.19.
 
Unless otherwise indicated
using qgroups:        No

using compression:    Yes, compress-force=zstd
number of snapshots:  Zero
number of subvolumes: top level subvolume only
raid profile:         None
using bcache:         No
layered on md or lvm: No
 
 
vhost002
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data/datastore2 btrfs rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
 
# smartctl -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled

 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
vhost003
# grep btrfs /etc/mtab
/dev/sdb4 /usr/local/data/datastore2 btrfs rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
(RAID controller)
# smartctl -l scterc /dev/sdb
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.17.0-0.bpo.1-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org


# btrfs dev stats /usr/local/data/datastore2
[/dev/sdb4].write_io_errs   0
[/dev/sdb4].read_io_errs    0
[/dev/sdb4].flush_io_errs   0
[/dev/sdb4].corruption_errs 0
[/dev/sdb4].generation_errs 0

 
 
vhost004
# grep btrfs /etc/mtab
/dev/sdb4 /usr/local/data/datastore2 btrfs rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
(RAID controller)
# smartctl -l scterc /dev/sdb
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.17.0-0.bpo.1-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, [ www.smartmontools.org ]( http://www.smartmontools.org )

 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdb4].write_io_errs   0
[/dev/sdb4].read_io_errs    0
[/dev/sdb4].flush_io_errs   0
[/dev/sdb4].corruption_errs 0
[/dev/sdb4].generation_errs 0

 
 
vhost031
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data/datastore2 btrfs rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
# smartctl -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled

 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
vhost032
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data/datastore2 btrfs rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
# smartctl -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled

 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
vhost182
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data/datastore2 btrfs rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
 
# smartctl -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled
 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
vhost241
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data/datastore2 btrfs rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
# smartctl -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.17.0-0.bpo.1-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled

 
# btrfs dev stats /usr/local/data/datastore2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
lxc008
number of subvolumes: 1416

 
# grep btrfs /etc/mtab
/dev/sdc1 /usr/local/data2 btrfs rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
(RAID controller)
# smartctl -d megaraid,0 -l scterc /dev/sdc
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

Write SCT (Get) Error Recovery Control Command failed: ATA return descriptor not supported by controller firmware
SCT (Get) Error Recovery Control command failed

 
# btrfs dev stats /usr/local/data2
[/dev/sdc1].write_io_errs   0
[/dev/sdc1].read_io_errs    0
[/dev/sdc1].flush_io_errs   0
[/dev/sdc1].corruption_errs 0
[/dev/sdc1].generation_errs 0

 
 
lxc009
# grep btrfs /etc/mtab
/dev/sda3 / btrfs rw,relatime,space_cache,subvolid=5,subvol=/ 0 0
/dev/sdb1 /usr/local/data2 btrfs rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0

 
(RAID controller)
# smartctl -l scterc /dev/sdb
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, [ www.smartmontools.org ]( http://www.smartmontools.org )

 
# btrfs dev stats /usr/local/data2
[/dev/sdb1].write_io_errs   0
[/dev/sdb1].read_io_errs    0
[/dev/sdb1].flush_io_errs   0
[/dev/sdb1].corruption_errs 0
[/dev/sdb1].generation_errs 0

 

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

#63447

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

Control: tags -1 -unreproducible

Hi Russell,

Thank you for providing more info.  Now I see where you're running
into known limitations with btrfs (all versions).  Reply follows inline.

BTW, you're not using SMR and/or USB disks, right?

On Mon, Feb 25, 2019 at 12:33:51PM -0600, Russell Mosemann wrote:
>    Steps to reproduce
> 
>    Simply copying a file into the file system can cause things to lock up. In
>    this case, the files will usually be thin-provisioned qcow2 disks for kvm
>    vm's. There is no detailed formula to force the lockup to occur, but it
>    happens regularly, sometimes multiple times in one day.
>

Have you read https://wiki.debian.org/Btrfs ?  Specifically "COW on
COW: Don't do it!" ?  If you did read it, maybe the document needs to
be more firm about this...  eg: "take care to use raw images" should
be "under no circumstances use non-raw images".  P.S. Yes, I know that
page would benefit from a reorganisation...  Sorry about it's current
state.

>    Files are often copied from a master by reference (cp --reflink), one per
>    day to perform a daily backup for up to 45 days. Removing older files is a
>    painfully slow process, even though there are only 45 files in the
>    directory. Doing a scrub is almost a sure way to lock up the system,
>    especially if a copy or delete operation is in progress. On two systems,
>    crashes occur with 4.18 and 4.19 but not 4.17. On the other systems that
>    crash, it does not seem to matter if it is 4.17, 4.18 or 4.19.
>

It might be that >4.17 fixed some corner-case corruption issue, for
example by adding an additional check during each step of a backref
walk, and that this makes the timeout more frequent and severe. eg:
4.17 works because it is less strict.

By the way, is it your VM host that locks up, or your VM guests?  Do[es]
they[it] recover if you leave it alone for many hours?  I didn't see
any oopses or panics in your kernel logs.

Reflinked file are like snapshots, any I/O on a file must walk every branch
of the backref tree that is relevant to a file.  For more info see:
  https://btrfs.wiki.kernel.org/index.php/Resolving_Extent_Backrefs

As the tree grows and becomes more complex, a COW fs will get slower.
You've hit the >120sec threshold, due to one or more of the issues
discussed in this email.  eg: a scrub, even during a file copy/delete
should never cause this timeout.  I haven't experienced one since
linux-4.4.x or 4.9.x...

To get a figure that will provide a sense of scale to how many
operations it takes to do anything other than reflink or snapshot you
can consult the output of:

  filefrag each_live_copy_vm_image

I expect the number of extends will exceed tens of thousands.  BTW,
you can use btrfsmaintenance to periodically defrag the source (and
only the source) images.  Note that this will break reflinks between
SOURCE and each of the 45 REFLINKED-COPIES, but not between
REFLINK-COPY1 and REFLINK-COPY2.  Defragging weekly strikes a nice
balance between lost space efficiency (due to fewer shared references
between today's backup and yesterday's) and avoiding the performance
issue you've encountered.  Mounting with autodefrag is the least space
efficient.  (P.S. Also, I don't trust autodefrag)

IIRC btrfs-debug-tree can accurately count references.

>    Unless otherwise indicated
> 
>    using qgroups:        No
>

Whew, thank you for not! :-)  Qgroups make this kind of issue worse.

>    using compression:    Yes, compress-force=zstd
>

If userspace CPU usage is already high then compression may introduce
additional latency and contribute to the >120sec warning.

>    number of snapshots:  Zero
>

But 45 reflinked copies per VM.

>    number of subvolumes: top level subvolume only
>

I believe it was Chris Murphy who wrote (on linux-btrfs) about how
segmenting different functions/datasets into different
non-hierarchically structured (eg: flat layout) subvolumes reduces
lock contention during backref walks.  This is a performance tuning
tip that needs to be investigated and integrated into the wiki
article.  Eg:

           _____id:5 top-level_____   <-either unmounted, or           
          /    |     |     |       \    mounted somewhere like
         /     |     |     |        \   /.btrfs-admin, /.volume, etc.
        /      |     |     |         \
host_rootfs   VM0   VM1   VM2   data_shared_between_VMs

>    raid profile:         None
> 
>    using bcache:         No
>

Thanks.

>    layered on md or lvm: No
>

But layered on hardware raid?

>    vhost002
> 
>    # grep btrfs /etc/mtab
>    /dev/sdc1 /usr/local/data/datastore2 btrfs
>    rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
> 

[1] Thank you for using noatime.  Please explain this configuration.
eg: does each VM have three virtual disks (containing btrfs volumes),
backed by qcow2 images, backed by a btrfs volume on the VM host?  I
thought you were using qcow2 images, but this looks like passthrough
of some kind.

If the former:

Every write causes a COW operation in the inner btrfs, and the qcow2,
and the outer btrfs volume.  The inner btrfs volume compresses once,
and then the outer btrfs volume will try to compress again.

>    # smartctl -l scterc /dev/sdc
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
> 
>    SCT Error Recovery Control:
>               Read: Disabled
>              Write: Disabled
>

[2] Have you seen any SATA resets in your logs?  The default kernel
timeout is 30sec, and drives without SCR ERT can sometimes take an
undefined (though generally under 180sec) amount of time to reattempt
to read a block...and if it's an SMR drive with writing I/O the delay
to successful read can be even worse.

>    vhost003
> 
>    # grep btrfs /etc/mtab
>    /dev/sdb4 /usr/local/data/datastore2 btrfs
>    rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

[1]  Also, why aren't you using noatime here too?

>    (RAID controller)
> 
>    # smartctl -l scterc /dev/sdb
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.17.0-0.bpo.1-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
>

[4] Ok, so sdb is the raid controller on the host?  And sdb is passed
through, and you shutdown one VM before mounting the same
btrfs-on-hardware_RAID partition in another VM?

>    vhost004
> 
>    # grep btrfs /etc/mtab
>    /dev/sdb4 /usr/local/data/datastore2 btrfs
>    rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

[3] [1].  Also, why aren't you using noatime here too?

>    (RAID controller)
> 
>    # smartctl -l scterc /dev/sdb
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.17.0-0.bpo.1-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
>
>     
> 
>    # btrfs dev stats /usr/local/data/datastore2
>    [/dev/sdb4].write_io_errs   0
>    [/dev/sdb4].read_io_errs    0
>    [/dev/sdb4].flush_io_errs   0
>    [/dev/sdb4].corruption_errs 0
>    [/dev/sdb4].generation_errs 0
>

[4] So vhost03 and vhost04 mount the same partition from the raid
controller on the host via passthrough?  At the same time?

>    vhost031
> 
>    # grep btrfs /etc/mtab
>    /dev/sdc1 /usr/local/data/datastore2 btrfs
>    rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

[3] [4]

>    # smartctl -l scterc /dev/sdc
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
> 
>    SCT Error Recovery Control:
>               Read: Disabled
>              Write: Disabled
>

[2]

>    vhost032
> 
>    # grep btrfs /etc/mtab
>    /dev/sdc1 /usr/local/data/datastore2 btrfs
>    rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

[3] [4]

>    # smartctl -l scterc /dev/sdc
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
> 
>    SCT Error Recovery Control:
>               Read: Disabled
>              Write: Disabled
>

Is this sdc a qcow2 image or a passed through megaraid partition?

>    vhost182
> 
>    # grep btrfs /etc/mtab
>    /dev/sdc1 /usr/local/data/datastore2 btrfs
>    rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

[1]

[snip]

>    lxc008
> 
>    number of subvolumes: 1416

That's *way* too many.  This is a major contributing factor to the
timeouts...

[snip]

>    # grep btrfs /etc/mtab
>    /dev/sdc1 /usr/local/data2 btrfs
>    rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>

Is this in a container rather than a VM?

>    (RAID controller)
> 
>    # smartctl -d megaraid,0 -l scterc /dev/sdc
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
> 
>    Write SCT (Get) Error Recovery Control Command failed: ATA return
>    descriptor not supported by controller firmware
>    SCT (Get) Error Recovery Control command failed
> 

A different raid controller?  Aiie, this is a complex setup... 

>    lxc009
> 
>    # grep btrfs /etc/mtab
>    /dev/sda3 / btrfs rw,relatime,space_cache,subvolid=5,subvol=/ 0 0
>    /dev/sdb1 /usr/local/data2 btrfs
>    rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
> 
>     
> 
>    (RAID controller)
> 
>    # smartctl -l scterc /dev/sdb
>    smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64] (local
>    build)
>    Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    www.smartmontools.org
> 
>     
> 
>    # btrfs dev stats /usr/local/data2
>    [/dev/sdb1].write_io_errs   0
>    [/dev/sdb1].read_io_errs    0
>    [/dev/sdb1].flush_io_errs   0
>    [/dev/sdb1].corruption_errs 0
>    [/dev/sdb1].generation_errs 0
> 

Ok, first decide where you want to reflink/snapshot, either inside the
VMs or outside.

If inside:
  * Host your VM images on an ext4 or xfs partition.
  * Use btrfs inside the VM.
    - Use noatime inside the VM.
  * To get backups onto the host, use the network or a
    passed-through partition.

If outside:
  * Host raw VM images on btrfs (noatime).
  * Use ext4 on xfs inside the VM.
    - Everything is already COWed, checksummed, and compressed on the
      VM host, so it's absolutely not needed here.
    - Also use noatime inside the VM.
  * Periodically defrag the live copy of your VM images.
  ! Note that many on the linux-btrfs mailing list do not recommend
    btrfs for this type of workload, if performance is important.
  ? Maybe the partition pass through is how you're getting around
    this issue?

Hacky "it's too late to rethink this server": Use chattr +C on the VM
images.  Note that the images will no longer be checksummed (see
wiki).

Maybe I've misunderstood, but it looks like you're running btrfs
volumes, on top of qcow2 images, on top of a btrfs host volume.
That's an easy to reproduce recipe for problems of this kind.


Sincerely,
Nicholas

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

#63455

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

Two servers hung last night. Both events happened while a file was being copied into the btrfs file system. No references or vm's were involved. It was a simple file copy.
 
I had the opportunity to observe the system while it happened. It turns out that the CPU time goes to 50% or more I/O wait. The servers have 6 cores/12 threads running at 3.5GHz. It is like the operating system goes into an infinite loop, banging away at the disk. Letting it sit for hours does not resolve the problem. The only solution I'm aware of at this time is to reboot the server. Restarting the copy process after a reboot sometimes triggers the same bug, and sometimes it works fine.
 
--
Russell Mosemann

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

#63457

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

I ran a "btrfs check" on one of the partitions that had issues last night to confirm that the file system was not damaged. No errors were found.
 
# btrfs check -p /dev/sdc1
Checking filesystem on /dev/sdc1
UUID: d6640b4b-bd59-47d5-bfd7-37b4c40fb3c6
checking extents [.]
checking free space cache [o]
checking fs roots [O]
checking only csum items (without verifying data)
checking root refs
found 1453455912960 bytes used, no error found
total csum bytes: 1411701148
total tree bytes: 7534133248
total fs tree bytes: 3358851072
total extent tree bytes: 2426896384
btree space waste bytes: 695281951
file data blocks allocated: 3067911655424
 referenced 6563527507968
 

--
Russell Mosemann

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

#63475

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

We continue to see hangs on one or more servers every night. It happens when copying a file into the btrfs partition. The result of the hang is that the CPU goes to 50% I/O wait or higher for hours. Only a reboot resets the process.
 
Based on this behavior and the kernel errors, it looks like btrfs has a bug with managing extents and caching in the presence of compression that causes it to go into an infinite loop that continually reads or writes to the disk. This seems to be 100% reproducible when the right file is found. Rebooting and immediately restarting the copy process with the same file results in the same hang.
 
--
Russell Mosemann
 

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

#63476

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

Hi Russell,

The backport of btrfs-progs is old and doesn't have libzstd support,
and I'm still waiting for a sponsor (#922951), but if you'd like to
give it a try before it hits the archive:

  dget https://mentors.debian.net/debian/pool/main/b/btrfs-progs/btrfs-progs_4.20.1-2~bpo9+1.dsc

  cd btrfs-progs-4.20.1/
  dpkg-buildpackage -us -uc  # will require the installation of build-deps
  cd ../
  sudo dpkg -i btrfs-progs_4.20.1-2~bpo9+1_amd64.deb \
    btrfs-tools_4.20.1-2~bpo9+1_amd64.deb \
    libbtrfs0_4.20.1-2~bpo9+1_amd64.deb \
    libbtrfsutil1_4.20.1-2~bpo9+1_amd64.deb \
    python3-btrfsutil_4.20.1-2~bpo9+1_amd64.deb

I will confess that I don't know if btrfs-check actually needs libzstd
support to check fs structures, or if --check-data-csum requires it,
but if this bug is forwarded then upstream will ask if btrfs-check
found anything using a recent version of btrfs-progs.

On Tue, Feb 26, 2019 at 11:29:25AM -0600, Russell Mosemann wrote:
>    On Monday, February 25, 2019 10:17pm, "Nicholas D Steeves"
>    <nsteeves@gmail.com> said:
> 
>    > On Mon, Feb 25, 2019 at 12:33:51PM -0600, Russell Mosemann wrote:
>    >
> 
>    In every case, the btrfs partition is used exclusively as an archive for
>    backups. In no circumstance is a vm or something like a database run on
>    the partition. Consequently, it is not possible for CoW on CoW to happen.
>    The partition is simply storing files.
>
[snip]
>    >
>    > It might be that >4.17 fixed some corner-case corruption issue, for
>    > example by adding an additional check during each step of a backref
>    > walk, and that this makes the timeout more frequent and severe. eg:
>    > 4.17 works because it is less strict.
>    >
>    > By the way, is it your VM host that locks up, or your VM guests? Do[es]
>    > they[it] recover if you leave it alone for many hours? I didn't see
>    > any oopses or panics in your kernel logs.
> 
>     
> 
>    It is the host that locks up. This does not involve vm's in any way. If
>    vm's are present, they are running on different drives. Some of the vm's
>    even use btrfs partitions themselves. None of the vm's experience issues
>    with their btrfs volumes. None of the vm's are affected by the hung btrfs
>    tasks on the host. That is because the issue exclusively involves the
>    separate, dedicated, archive partition used by the host. For all practical
>    purposes, vm's aren't part of this picture.
>

Right.  This simplifies things.  So:

1) VM images and backup target are on different volumes on the same
host.
2) VM images are copied between volumes using "cp --reflink"
  * IIRC the VM images are stored on a btrfs volume, on the host?
3) Because this is an inter-volume copy, "cp --reflink=always vhost002.img
/megaraid/backup" should emit a warning or fail.
  * please confirm that it warns or fails.

I think you said that the following two things will also produce a hang?

  cp --reflink /megaraid/backup/vhost002.img /megaraid/vhost002.img.0 ?

or

   rm /megaraid/backup/vhost002.img.44 # oldest backup ?

Yes, Btrfs struggles with large sparse files...and these limitations
are amplified by the 45 reflinked copies, amplified when using
deduplication (I'm assuming you're not using this, btw), and amplified
by transparent compression.  If this class of bugs is at fault, then
tests will fail at (5) (see below).

>    As far as I am aware, a hung task does not recover, even after many hours.
>    A number of times, it has hung at night. When I check in the morning hours
>    later, it is still hung. In many cases, the server must be forcibly
>    rebooted, because the hung task hangs the reboot process.
>

Back in the linux-3.16 to 4.4 days btrfs hung tasks were often
triggered by desktop databases such as those used by Thunderbird or
Firefox, and were quite common.  My laptop always recovered after
about 15-20 minutes...

[snipped info on counting fragments and references]
>    This is useful information, but it doesn't seem directly related to the
>    hung tasks. The btrfs tasks hang when a file is being copied into the
>    btrfs partition. No references or vm's are involved in that process. It is
>    a simple file copy.
>

If the source volume is btrfs then it will have to do the complex
backref work when reading a VM.img.  Because it's an intervolume cp,
and cp defaults to "--sparse=auto" /megaraid/VM.img should be written
sparsely, in one go, and reading from the resulting copy should not
have the overhead of reading from the master copy VM.img (the backup
copy should not replicate the fragmentation of the master copy when
copied in this way).  This can be confirmed by comparing the filefrag
output for_each_VM.img to for_each_backup_copy.img

>    > > using compression: Yes, compress-force=zstd
>    > >
>    >
>    > If userspace CPU usage is already high then compression may introduce
>    > additional latency and contribute to the >120sec warning.
> 
>    There is more than plenty CPU. Depending on the server, there are 12 to 16
>    threads running at 2.67GHz to 3.5GHz. The servers have 64GB or more of
>    memory. The servers are not loaded during the day, and the backups take
>    place at night, when not much else is happening. It is difficult to
>    imagine a scenario where it would take longer than 120 seconds to compress
>    a block.
>

Unlike ZFS, blocks aren't compressed; large extents are:
  https://btrfs.wiki.kernel.org/index.php/Compression
  https://btrfs.wiki.kernel.org/index.php/Resolving_Extent_Backrefs
  https://btrfs.wiki.kernel.org/index.php/Btrfs_design#Extent_Block_Groups

>    When I look at the kernel errors, they involve btrfs cleanup transactions,
>    dirty blocks, caching and extents. I don't recall ever seeing a reference
>    to compression in a call trace.
>

Have you installed linux-image-4.19.0-0.bpo.2-amd64 and
linux-image-4.19.0-0.bpo.2-amd64-dbg (or their unsigned variants) yet?

>    > > number of snapshots: Zero
>    > >
>    >
>    > But 45 reflinked copies per VM.
>    >
>    > > number of subvolumes: top level subvolume only
>    > >
>    >
>    > I believe it was Chris Murphy who wrote (on linux-btrfs) about how
>    > segmenting different functions/datasets into different
>    > non-hierarchically structured (eg: flat layout) subvolumes reduces
>    > lock contention during backref walks. This is a performance tuning
>    > tip that needs to be investigated and integrated into the wiki
>    > article. Eg:
>    >
>    > _____id:5 top-level_____ <-either unmounted, or
>    > / | | | \ mounted somewhere like
>    > / | | | \ /.btrfs-admin, /.volume, etc.
>    > / | | | \
>    > host_rootfs VM0 VM1 VM2 data_shared_between_VMs
> 
>     
> 
>    This is an interesting idea, but it implies that btrfs does not handle
>    large files or large file systems very well. The trick is to make it look
>    like multiple, small file systems.
>

Correct, the upstream development focus is mostly on stabilisation
(and to a certain extent adding new features) and not on performance.
At this time there seems to be consensus on the linux-btrfs mailing
list that ext4 or xfs should be used in preference to btrfs for
volumes holding VM images, and that nodatacow isn't that great.
"large files" is not the issue; however, VM images and databases are.

That said, storing (non-live) backup copies of VM images is a good use
case for btrfs.

[snip]

>    I have carefully checked the logs for months for an explanation of why
>    btrfs is hanging, and I have never seen any other error message. If this
>    were one host, then a SATA reset might be in the set of possibilities, but
>    since this involves multiple hosts on different architectures with and
>    without RAID, a SATA reset as the only explanation for all of the hangs is
>    improbable.

Agreed!

>    We briefly experimented with SMR drives, and the performance was abysmal.
>

Thanks for confirming.

>    > > vhost003
>    > >
>    > > # grep btrfs /etc/mtab
>    > > /dev/sdb4 /usr/local/data/datastore2 btrfs
>    > > rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>    > >
>    >
>    > [1] Also, why aren't you using noatime here too?
> 
>     
> 
>    noatime is a more recent change, as an experiment to determine if it would
>    affect hangs. It has not been implemented on all hosts, yet. The presence
>    or absence of noatime does not appear to affect hangs, which makes sense,
>    because hangs happen during writes, not reads.
>

FYI, btrfs always runs better with noatime, because without this each
read will update the atime (once a day with relatime), and each atime
update will trigger a COW operation for each file that is read.

[snip]
>    > > lxc008
>    > >
>    > > number of subvolumes: 1416
>    >
>    > That's *way* too many. This is a major contributing factor to the
>    > timeouts...
> 
>     
> 
>    lxc008 does not experience btrfs transaction hangs with 4.17. It does
>    experience hangs with 4.18 and 4.19. Those hangs happen shortly after a
>    copy starts. From that perspective, a hang is easily reproducible.
> 
>    > [snip]
>    >
>    > > # grep btrfs /etc/mtab
>    > > /dev/sdc1 /usr/local/data2 btrfs
>    > > rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
>    > >
>    >
>    > Is this in a container rather than a VM?
> 
>     
> 
>    lxc008 is a physical host that runs containers, rather than vm's. The
>    btrfs partition is a separate partition on the RAID array. The btrfs
>    partition is only used to store backup files.
> 
>    > > (RAID controller)
>    > >
>    > > # smartctl -d megaraid,0 -l scterc /dev/sdc
>    > > smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64]
>    (local
>    > > build)
>    > > Copyright (C) 2002-16, Bruce Allen, Christian Franke,
>    > > www.smartmontools.org
>    > >
>    > > Write SCT (Get) Error Recovery Control Command failed: ATA return
>    > > descriptor not supported by controller firmware
>    > > SCT (Get) Error Recovery Control command failed
>    > >
>    >
>    > A different raid controller? Aiie, this is a complex setup...
> 
>     
> 
>    They are all simple setups. Either the host has a dedicated hard drive for
>    the btrfs partition, or the host has a RAID array where the btrfs
>    partition is located.
>

Oh...  It would have been nice to know there were multiple physical
sytems early on :-/

[snip]
>    > Maybe I've misunderstood, but it looks like you're running btrfs
>    > volumes, on top of qcow2 images, on top of a btrfs host volume.
>    > That's an easy to reproduce recipe for problems of this kind.
>    >
>    >
>    > Sincerely,
>    > Nicholas
>    >
> 
>     
> 
>    This last part kind of went off the rails. We are only talking about one
>    btrfs partition per physical host, which is only used to store backups. It
>    is the most simple, vanilla situation, which should be perfectly suited
>    for a file system.
>

This would have been nice to know at the onset...  Please pick one
host without a megaraid for the purposes of this bug.  I'll assume
that one host is not in production and can afford to crash, that you
have external backups, and (optionally) that you can add a SAS or SATA
connected hard drive.

1) 
Install the newest bpo kernel and its dbg package on this machine,
along with the locally-compiled btrfs-progs 4.20.x bpo (if you prefer
I can upload it somewhere).

Add "scsi_mod.use_blk_mq=0" as a kernel argument and update-grub, or
manually edit at the grub menu.  This removes the new blk-mq as a
variable.

Add a new disk, partition it, format it using btrfs-progs 4.20.x, and
mount without compression.  This removes compression as a variable,
which is notable, because most corruption or crash reports on
linux-btrfs involve transparent compression.  It also removes ancient
file systems structures as a variable.  Yes, really.  There is a large
class of reports on linux-btrfs that are caused by the lint of various
allocation bugs in past kernels. (a)

To isolate the kernel reader from the writer, netcat (or ssh) a VM
image from another machine.

If it crashes then, we'll have a simple reproducible case for core
btrfs functionality.  I expect this test case to pass.

2)
Try again with scsi_mod.use_blk_mq=1.  If this fails the bug is due to
a blk-mq bug, or malinteraction between blk-mq and btrfs.  I'm not
sure if this one will pass or fail.  If it fails then this bug might
be a duplicate of #913138.

3)
Try again with scsi_mod.use_blk_mq=0, but this time mount with
compress=zstd.  This test will fail if it's a zstd compressed extent
bug.

4) Try again with scsi_mod.use_blk_mq=1 (kernel default), with
compress=zstd.  This is the closest to your existing test case.  It
will fail, unless (a) is the cause.

5) If for some reason all of 1-to-4 pass, then redo them without
isolating the reader and the writer on different machines.  This
probably won't be necessary.

--

If everything passes, then try 1, 2, and maybe 3 on a one of the
systems with a megaraid to test for a malinteraction between this HBA
and blk-mq--I think it's highly unlikely it will come to this!


Cheers,
Nicholas

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

#63477

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

I used btrfs-progs (4.17-1~bpo9+1) from the backports repository, which does have zstd support. btrfs-check does need zstd support. Otherwise, it will error out with unsupported feature (10).
 
--
Russell Mosemann

-----Original Message-----
From: "Nicholas D Steeves" <nsteeves@gmail.com>
Sent: Saturday, March 2, 2019 3:59pm
To: "Russell Mosemann" <rmosemann@futurefoam.com>, 908216@bugs.debian.org
Subject: Re: Bug#908216: btrfs blocked for more than 120 seconds



Hi Russell,

The backport of btrfs-progs is old and doesn't have libzstd support,
and I'm still waiting for a sponsor (#922951), but if you'd like to
give it a try before it hits the archive:

 dget https://mentors.debian.net/debian/pool/main/b/btrfs-progs/btrfs-progs_4.20.1-2~bpo9+1.dsc

 cd btrfs-progs-4.20.1/
 dpkg-buildpackage -us -uc # will require the installation of build-deps
 cd ../
 sudo dpkg -i btrfs-progs_4.20.1-2~bpo9+1_amd64.deb \
 btrfs-tools_4.20.1-2~bpo9+1_amd64.deb \
 libbtrfs0_4.20.1-2~bpo9+1_amd64.deb \
 libbtrfsutil1_4.20.1-2~bpo9+1_amd64.deb \
 python3-btrfsutil_4.20.1-2~bpo9+1_amd64.deb

I will confess that I don't know if btrfs-check actually needs libzstd
support to check fs structures, or if --check-data-csum requires it,
but if this bug is forwarded then upstream will ask if btrfs-check
found anything using a recent version of btrfs-progs.

On Tue, Feb 26, 2019 at 11:29:25AM -0600, Russell Mosemann wrote:
> On Monday, February 25, 2019 10:17pm, "Nicholas D Steeves"
> <nsteeves@gmail.com> said:
> 
> > On Mon, Feb 25, 2019 at 12:33:51PM -0600, Russell Mosemann wrote:
> >
> 
> In every case, the btrfs partition is used exclusively as an archive for
> backups. In no circumstance is a vm or something like a database run on
> the partition. Consequently, it is not possible for CoW on CoW to happen.
> The partition is simply storing files.
>
[snip]
> >
> > It might be that >4.17 fixed some corner-case corruption issue, for
> > example by adding an additional check during each step of a backref
> > walk, and that this makes the timeout more frequent and severe. eg:
> > 4.17 works because it is less strict.
> >
> > By the way, is it your VM host that locks up, or your VM guests? Do[es]
> > they[it] recover if you leave it alone for many hours? I didn't see
> > any oopses or panics in your kernel logs.
> 
> 
> 
> It is the host that locks up. This does not involve vm's in any way. If
> vm's are present, they are running on different drives. Some of the vm's
> even use btrfs partitions themselves. None of the vm's experience issues
> with their btrfs volumes. None of the vm's are affected by the hung btrfs
> tasks on the host. That is because the issue exclusively involves the
> separate, dedicated, archive partition used by the host. For all practical
> purposes, vm's aren't part of this picture.
>

Right. This simplifies things. So:

1) VM images and backup target are on different volumes on the same
host.
2) VM images are copied between volumes using "cp --reflink"
 * IIRC the VM images are stored on a btrfs volume, on the host?
3) Because this is an inter-volume copy, "cp --reflink=always vhost002.img
/megaraid/backup" should emit a warning or fail.
 * please confirm that it warns or fails.

I think you said that the following two things will also produce a hang?

 cp --reflink /megaraid/backup/vhost002.img /megaraid/vhost002.img.0 ?

or

 rm /megaraid/backup/vhost002.img.44 # oldest backup ?

Yes, Btrfs struggles with large sparse files...and these limitations
are amplified by the 45 reflinked copies, amplified when using
deduplication (I'm assuming you're not using this, btw), and amplified
by transparent compression. If this class of bugs is at fault, then
tests will fail at (5) (see below).

> As far as I am aware, a hung task does not recover, even after many hours.
> A number of times, it has hung at night. When I check in the morning hours
> later, it is still hung. In many cases, the server must be forcibly
> rebooted, because the hung task hangs the reboot process.
>

Back in the linux-3.16 to 4.4 days btrfs hung tasks were often
triggered by desktop databases such as those used by Thunderbird or
Firefox, and were quite common. My laptop always recovered after
about 15-20 minutes...

[snipped info on counting fragments and references]
> This is useful information, but it doesn't seem directly related to the
> hung tasks. The btrfs tasks hang when a file is being copied into the
> btrfs partition. No references or vm's are involved in that process. It is
> a simple file copy.
>

If the source volume is btrfs then it will have to do the complex
backref work when reading a VM.img. Because it's an intervolume cp,
and cp defaults to "--sparse=auto" /megaraid/VM.img should be written
sparsely, in one go, and reading from the resulting copy should not
have the overhead of reading from the master copy VM.img (the backup
copy should not replicate the fragmentation of the master copy when
copied in this way). This can be confirmed by comparing the filefrag
output for_each_VM.img to for_each_backup_copy.img

> > > using compression: Yes, compress-force=zstd
> > >
> >
> > If userspace CPU usage is already high then compression may introduce
> > additional latency and contribute to the >120sec warning.
> 
> There is more than plenty CPU. Depending on the server, there are 12 to 16
> threads running at 2.67GHz to 3.5GHz. The servers have 64GB or more of
> memory. The servers are not loaded during the day, and the backups take
> place at night, when not much else is happening. It is difficult to
> imagine a scenario where it would take longer than 120 seconds to compress
> a block.
>

Unlike ZFS, blocks aren't compressed; large extents are:
 https://btrfs.wiki.kernel.org/index.php/Compression
 https://btrfs.wiki.kernel.org/index.php/Resolving_Extent_Backrefs
 https://btrfs.wiki.kernel.org/index.php/Btrfs_design#Extent_Block_Groups

> When I look at the kernel errors, they involve btrfs cleanup transactions,
> dirty blocks, caching and extents. I don't recall ever seeing a reference
> to compression in a call trace.
>

Have you installed linux-image-4.19.0-0.bpo.2-amd64 and
linux-image-4.19.0-0.bpo.2-amd64-dbg (or their unsigned variants) yet?

> > > number of snapshots: Zero
> > >
> >
> > But 45 reflinked copies per VM.
> >
> > > number of subvolumes: top level subvolume only
> > >
> >
> > I believe it was Chris Murphy who wrote (on linux-btrfs) about how
> > segmenting different functions/datasets into different
> > non-hierarchically structured (eg: flat layout) subvolumes reduces
> > lock contention during backref walks. This is a performance tuning
> > tip that needs to be investigated and integrated into the wiki
> > article. Eg:
> >
> > _____id:5 top-level_____ <-either unmounted, or
> > / | | | \ mounted somewhere like
> > / | | | \ /.btrfs-admin, /.volume, etc.
> > / | | | \
> > host_rootfs VM0 VM1 VM2 data_shared_between_VMs
> 
> 
> 
> This is an interesting idea, but it implies that btrfs does not handle
> large files or large file systems very well. The trick is to make it look
> like multiple, small file systems.
>

Correct, the upstream development focus is mostly on stabilisation
(and to a certain extent adding new features) and not on performance.
At this time there seems to be consensus on the linux-btrfs mailing
list that ext4 or xfs should be used in preference to btrfs for
volumes holding VM images, and that nodatacow isn't that great.
"large files" is not the issue; however, VM images and databases are.

That said, storing (non-live) backup copies of VM images is a good use
case for btrfs.

[snip]

> I have carefully checked the logs for months for an explanation of why
> btrfs is hanging, and I have never seen any other error message. If this
> were one host, then a SATA reset might be in the set of possibilities, but
> since this involves multiple hosts on different architectures with and
> without RAID, a SATA reset as the only explanation for all of the hangs is
> improbable.

Agreed!

> We briefly experimented with SMR drives, and the performance was abysmal.
>

Thanks for confirming.

> > > vhost003
> > >
> > > # grep btrfs /etc/mtab
> > > /dev/sdb4 /usr/local/data/datastore2 btrfs
> > > rw,relatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
> > >
> >
> > [1] Also, why aren't you using noatime here too?
> 
> 
> 
> noatime is a more recent change, as an experiment to determine if it would
> affect hangs. It has not been implemented on all hosts, yet. The presence
> or absence of noatime does not appear to affect hangs, which makes sense,
> because hangs happen during writes, not reads.
>

FYI, btrfs always runs better with noatime, because without this each
read will update the atime (once a day with relatime), and each atime
update will trigger a COW operation for each file that is read.

[snip]
> > > lxc008
> > >
> > > number of subvolumes: 1416
> >
> > That's *way* too many. This is a major contributing factor to the
> > timeouts...
> 
> 
> 
> lxc008 does not experience btrfs transaction hangs with 4.17. It does
> experience hangs with 4.18 and 4.19. Those hangs happen shortly after a
> copy starts. From that perspective, a hang is easily reproducible.
> 
> > [snip]
> >
> > > # grep btrfs /etc/mtab
> > > /dev/sdc1 /usr/local/data2 btrfs
> > > rw,noatime,compress-force=zstd,space_cache,subvolid=5,subvol=/ 0 0
> > >
> >
> > Is this in a container rather than a VM?
> 
> 
> 
> lxc008 is a physical host that runs containers, rather than vm's. The
> btrfs partition is a separate partition on the RAID array. The btrfs
> partition is only used to store backup files.
> 
> > > (RAID controller)
> > >
> > > # smartctl -d megaraid,0 -l scterc /dev/sdc
> > > smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.2-amd64]
> (local
> > > build)
> > > Copyright (C) 2002-16, Bruce Allen, Christian Franke,
> > > www.smartmontools.org
> > >
> > > Write SCT (Get) Error Recovery Control Command failed: ATA return
> > > descriptor not supported by controller firmware
> > > SCT (Get) Error Recovery Control command failed
> > >
> >
> > A different raid controller? Aiie, this is a complex setup...
> 
> 
> 
> They are all simple setups. Either the host has a dedicated hard drive for
> the btrfs partition, or the host has a RAID array where the btrfs
> partition is located.
>

Oh... It would have been nice to know there were multiple physical
sytems early on :-/

[snip]
> > Maybe I've misunderstood, but it looks like you're running btrfs
> > volumes, on top of qcow2 images, on top of a btrfs host volume.
> > That's an easy to reproduce recipe for problems of this kind.
> >
> >
> > Sincerely,
> > Nicholas
> >
> 
> 
> 
> This last part kind of went off the rails. We are only talking about one
> btrfs partition per physical host, which is only used to store backups. It
> is the most simple, vanilla situation, which should be perfectly suited
> for a file system.
>

This would have been nice to know at the onset... Please pick one
host without a megaraid for the purposes of this bug. I'll assume
that one host is not in production and can afford to crash, that you
have external backups, and (optionally) that you can add a SAS or SATA
connected hard drive.

1) 
Install the newest bpo kernel and its dbg package on this machine,
along with the locally-compiled btrfs-progs 4.20.x bpo (if you prefer
I can upload it somewhere).

Add "scsi_mod.use_blk_mq=0" as a kernel argument and update-grub, or
manually edit at the grub menu. This removes the new blk-mq as a
variable.

Add a new disk, partition it, format it using btrfs-progs 4.20.x, and
mount without compression. This removes compression as a variable,
which is notable, because most corruption or crash reports on
linux-btrfs involve transparent compression. It also removes ancient
file systems structures as a variable. Yes, really. There is a large
class of reports on linux-btrfs that are caused by the lint of various
allocation bugs in past kernels. (a)

To isolate the kernel reader from the writer, netcat (or ssh) a VM
image from another machine.

If it crashes then, we'll have a simple reproducible case for core
btrfs functionality. I expect this test case to pass.

2)
Try again with scsi_mod.use_blk_mq=1. If this fails the bug is due to
a blk-mq bug, or malinteraction between blk-mq and btrfs. I'm not
sure if this one will pass or fail. If it fails then this bug might
be a duplicate of #913138.

3)
Try again with scsi_mod.use_blk_mq=0, but this time mount with
compress=zstd. This test will fail if it's a zstd compressed extent
bug.

4) Try again with scsi_mod.use_blk_mq=1 (kernel default), with
compress=zstd. This is the closest to your existing test case. It
will fail, unless (a) is the cause.

5) If for some reason all of 1-to-4 pass, then redo them without
isolating the reader and the writer on different machines. This
probably won't be necessary.

--

If everything passes, then try 1, 2, and maybe 3 on a one of the
systems with a megaraid to test for a malinteraction between this HBA
and blk-mq--I think it's highly unlikely it will come to this!


Cheers,
Nicholas

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

#63478

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

On Sat, Mar 02, 2019 at 05:12:42PM -0600, Russell Mosemann wrote:
>    I used btrfs-progs (4.17-1~bpo9+1) from the backports repository, which
>    does have zstd support. btrfs-check does need zstd support. Otherwise, it
>    will error out with unsupported feature (10).
> 

Unfortunately official 4.17-1~bpo9+1 does not, because Zstd support
wasn't enabled in Debian's btrfs-progs until 4.19.1-2; however, kernel
support for zstd+btrfs first appeared in linux-4.14.

wget
http://ftp.debian.org/debian/pool/main/b/btrfs-progs/btrfs-progs_4.17-1~bpo9+1+b1_amd64.deb
mkdir unpacked && cd unpacked
dpkg -x ../btrfs-progs_4.17-1~bpo9+1+b1_amd64.deb .
ldd bin/btrfs

        linux-vdso.so.1 (0x00007ffc6abea000)
        libuuid.so.1 => /lib/x86_64-linux-gnu/libuuid.so.1 (0x00007ff58fe60000)
        libblkid.so.1 => /lib/x86_64-linux-gnu/libblkid.so.1 (0x00007ff58fc1a000)
        libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007ff58fa00000)
        liblzo2.so.2 => /lib/x86_64-linux-gnu/liblzo2.so.2 (0x00007ff58f7de000)
        #    If libzstd.so.1 was linked in it would appear here.
        libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007ff58f5c1000)
        libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007ff58f222000)
        /lib64/ld-linux-x86-64.so.2 (0x00007ff59031d000)


Looking forward to the isolated writer test results!
Cheers,
Nicholas

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

#63508

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

The four most problematic servers were hanging nearly every day. They each have a dedicated hard drive and are running 4.19.0-0.bpo.2-amd64. I installed btrfs-progs 4.20.1 on each and recreated the file system on the hard drive. There have been no issues since then, but it is too early to tell. There are hardly any references or files on the drives. It might take up to a month to know if there is an issue.
 
--
Russell Mosemann

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

#63529

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

On Wed, Mar 06, 2019 at 07:55:45AM -0600, Russell Mosemann wrote:
>    The four most problematic servers were hanging nearly every day. They each
>    have a dedicated hard drive and are running 4.19.0-0.bpo.2-amd64. I
>    installed btrfs-progs 4.20.1 on each and recreated the file system on the
>    hard drive. There have been no issues since then, but it is too early to
>    tell. There are hardly any references or files on the drives. It might
>    take up to a month to know if there is an issue.
> 

Thanks for reformatting with newer -progs; this eliminates the most
difficult/impossible to reproduce factor.  Which of the five rounds of
tests from
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=908216#202 have you
started with?

It should be possible to accelerate triggering the bug by using the
network to send additional VM images from each server to the test
subject once a day.  eg: if four servers send VM images to a fifth
server then ideally (optimistically!) the bug would be triggered 80%
faster, and if everything is still all clear after a month then you'd
have at least 220 reflinked historical backups and five sparse copies
of large VM images.

Thank you for your work on making this bug reproducible.  This not
only accelerates its resolution (reproducible case in core
functionality needs to be forwarded upstream), but also provides
valuable data to inform our wiki's upcoming btrfs on buster
(linux-4.19) recommendations.

Cheers,
Nicholas

[toc] | [prev] | [standalone]

Back to top | Article view | linux.debian.kernel

csiph-web