Re: Rough (re)start with btrfs

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Wed, May 1, 2019 at 7:54 AM Hendrik Friedel <hendrik@xxxxxxxxxxxxx> wrote:
>
> Hello,
>
> as discussed in the other thread, I am migrating to BTRFS (again).
> Unfortunately, I had a bit of a rough start
> [Mo Apr 29 20:44:47 2019] INFO: task btrfs-transacti:10227 blocked for
> more than 120 seconds.
> [...]
> This repeated several times while moving data over. Full log of one
> instance below.
>
> I am using btrfs-progs v4.20.2 and debian stretch with
> 4.19.0-0.bpo.2-amd64 (I think, this is the latest Kernel available in
> stretch. Please correct if I am wrong.

What scheduler is being used for the drive?

# cat /sys/block/<dev>/queue/scheduler

If it's none, then kernel version and scheduler aren't likely related
to what you're seeing.

It's not immediately urgent, but I would still look for something
newer, just because the 4.19 series already has 37 upstream updates
released, each with dozens of fixes, easily there are over 1000 fixes
available in total. I'm not a Debian user but I think there's
stretch-backports that has newer kernels?
http://jensd.be/818/linux/install-a-newer-kernel-in-debian-9-stretch-stable



> [Mo Apr 29 20:44:47 2019] INFO: task btrfs-transacti:10227 blocked for
> more than 120 seconds.
> [Mo Apr 29 20:44:47 2019]       Not tainted 4.19.0-0.bpo.2-amd64 #1
> Debian 4.19.16-1~bpo9+1
> [Mo Apr 29 20:44:47 2019] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [Mo Apr 29 20:44:47 2019] btrfs-transacti D    0 10227      2 0x80000000
> [Mo Apr 29 20:44:47 2019] Call Trace:
> [Mo Apr 29 20:44:47 2019]  ? __schedule+0x3f5/0x880
> [Mo Apr 29 20:44:47 2019]  schedule+0x32/0x80
> [Mo Apr 29 20:44:47 2019]  wait_for_commit+0x41/0x80 [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? remove_wait_queue+0x60/0x60
> [Mo Apr 29 20:44:47 2019]  btrfs_commit_transaction+0x10b/0x8a0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? start_transaction+0x8f/0x3e0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  transaction_kthread+0x157/0x180 [btrfs]
> [Mo Apr 29 20:44:47 2019]  kthread+0xf8/0x130
> [Mo Apr 29 20:44:47 2019]  ? btrfs_cleanup_transaction+0x500/0x500
> [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? kthread_create_worker_on_cpu+0x70/0x70
> [Mo Apr 29 20:44:47 2019]  ret_from_fork+0x35/0x40
> [Mo Apr 29 20:44:47 2019] INFO: task kworker/u4:8:10576 blocked for more
> than 120 seconds.
> [Mo Apr 29 20:44:47 2019]       Not tainted 4.19.0-0.bpo.2-amd64 #1
> Debian 4.19.16-1~bpo9+1
> [Mo Apr 29 20:44:47 2019] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [Mo Apr 29 20:44:47 2019] kworker/u4:8    D    0 10576      2 0x80000000
> [Mo Apr 29 20:44:47 2019] Workqueue: events_unbound
> btrfs_async_reclaim_metadata_space [btrfs]
> [Mo Apr 29 20:44:47 2019] Call Trace:
> [Mo Apr 29 20:44:47 2019]  ? __schedule+0x3f5/0x880
> [Mo Apr 29 20:44:47 2019]  schedule+0x32/0x80
> [Mo Apr 29 20:44:47 2019]  wait_current_trans+0xb9/0xf0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? remove_wait_queue+0x60/0x60
> [Mo Apr 29 20:44:47 2019]  start_transaction+0x201/0x3e0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  flush_space+0x14d/0x5e0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x40/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x34/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x40/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x34/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x34/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x34/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x40/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x34/0x70
> [Mo Apr 29 20:44:47 2019]  ? __switch_to_asm+0x40/0x70
> [Mo Apr 29 20:44:47 2019]  ? get_alloc_profile+0x72/0x180 [btrfs]
> [Mo Apr 29 20:44:47 2019]  ? can_overcommit.part.63+0x55/0xe0 [btrfs]
> [Mo Apr 29 20:44:47 2019]  btrfs_async_reclaim_metadata_space+0xfb/0x4c0
> [btrfs]
> [Mo Apr 29 20:44:47 2019]  process_one_work+0x191/0x370
> [Mo Apr 29 20:44:47 2019]  worker_thread+0x4f/0x3b0
> [Mo Apr 29 20:44:47 2019]  kthread+0xf8/0x130
> [Mo Apr 29 20:44:47 2019]  ? rescuer_thread+0x340/0x340
> [Mo Apr 29 20:44:47 2019]  ? kthread_create_worker_on_cpu+0x70/0x70
> [Mo Apr 29 20:44:47 2019]  ret_from_fork+0x35/0x40

We need the entire dmesg so we can see if there are any earlier
complaints by the drive or the link. Can you attach the entire dmesg
as a file?

Also the output from

# smartctl -l gplog,0x13 /dev/sdX

If there's an error or it outputs nothing useful, then
# smarctl -x /dev/sdX

Also attach that as a file.

It's better if these things are file attachments, they're easier to
read, most MUAs do terrible line wraps.

-- 
Chris Murphy



[Index of Archives]     [Linux Filesystem Development]     [Linux NFS]     [Linux NILFS]     [Linux USB Devel]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]

  Powered by Linux