Task btrfs-transacti blocked for more than 120 seconds.

[Skeletonix]

Hello,

I'm facing quite annoying issue with btrfs file system on external USB hard drive. The drive is encrypted via LUKS. When it's under high load (usually backup via rsync) the drive froze with error:

[Sep11 18:40] INFO: task btrfs-transacti:1357 blocked for more than 120 seconds.
[ +0.000015] Not tainted 4.14.69-v7+ #1141
[ +0.000005] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ +0.000008] btrfs-transacti D 0 1357 2 0x00000000
[ +0.000046] [<8079d990>] (__schedule) from [<8079dff8>] (schedule+0x50/0xa8)
[ +0.000558] [<8079dff8>] (schedule) from [<7f50b754>] (btrfs_start_ordered_extent+0x128/0x158 [btrfs])
[ +0.000971] [<7f50b754>] (btrfs_start_ordered_extent [btrfs]) from [<7f50bcfc>] (btrfs_wait_ordered_range+0x140/0x18c [btrfs])
[ +0.000938] [<7f50bcfc>] (btrfs_wait_ordered_range [btrfs]) from [<7f53e2a0>] (__btrfs_wait_cache_io+0x50/0x1e4 [btrfs])
[ +0.000937] [<7f53e2a0>] (__btrfs_wait_cache_io [btrfs]) from [<7f540d18>] (btrfs_wait_cache_io+0x40/0x48 [btrfs])
[ +0.000926] [<7f540d18>] (btrfs_wait_cache_io [btrfs]) from [<7f4d4470>] (btrfs_start_dirty_block_groups+0x170/0x41c [btrfs])
[ +0.000928] [<7f4d4470>] (btrfs_start_dirty_block_groups [btrfs]) from [<7f4e7f44>] (btrfs_commit_transaction+0x154/0xc2c [btrfs])
[ +0.000928] [<7f4e7f44>] (btrfs_commit_transaction [btrfs]) from [<7f4e3100>] (transaction_kthread+0x1b4/0x1c8 [btrfs])
[ +0.000478] [<7f4e3100>] (transaction_kthread [btrfs]) from [<8013da6c>] (kthread+0x13c/0x16c)
[ +0.000021] [<8013da6c>] (kthread) from [<8010810c>] (ret_from_fork+0x14/0x28)
[ +0.000020] INFO: task python:3333 blocked for more than 120 seconds.
[ +0.000007] Not tainted 4.14.69-v7+ #1141
[ +0.000005] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ +0.000006] python D 0 3333 1 0x00000000
[ +0.000028] [<8079d990>] (__schedule) from [<8079dff8>] (schedule+0x50/0xa8)
[ +0.000473] [<8079dff8>] (schedule) from [<7f50b754>] (btrfs_start_ordered_extent+0x128/0x158 [btrfs])
[ +0.000928] [<7f50b754>] (btrfs_start_ordered_extent [btrfs]) from [<7f4ffe3c>] (lock_and_cleanup_extent_if_need+0x4d0/0x4dc [btrfs])
[ +0.000931] [<7f4ffe3c>] (lock_and_cleanup_extent_if_need [btrfs]) from [<7f50119c>] (__btrfs_buffered_write+0x1e0/0x78c [btrfs])
[ +0.000931] [<7f50119c>] (__btrfs_buffered_write [btrfs]) from [<7f505f10>] (btrfs_file_write_iter+0x268/0x668 [btrfs])
[ +0.000563] [<7f505f10>] (btrfs_file_write_iter [btrfs]) from [<8028b368>] (__vfs_write+0xe0/0x138)
[ +0.000025] [<8028b368>] (__vfs_write) from [<8028b588>] (vfs_write+0xb4/0x1bc)
[ +0.000023] [<8028b588>] (vfs_write) from [<8028b7d8>] (SyS_write+0x54/0xb0)
[ +0.000026] [<8028b7d8>] (SyS_write) from [<80108060>] (ret_fast_syscall+0x0/0x28)

Some times it is switched to read-only mode:

BTRFS: error (device dm-0) in btrfs_run_delayed_refs:3089: errno=-17 Object already exists
[ 2497.600549] BTRFS info (device dm-0): forced readonly
[ 2497.600553] BTRFS: Transaction aborted (error -17)
[ 2497.600556] Modules linked in: rfcomm btrfs xor xor_neon zstd_decompress zstd_compress xxhash lzo_compress raid6_pq zlib_deflate dm_crypt aes_arm_bs crypto_simd cryptd algif_skcipher af_alg dm_mod dax sg bnep hci_uart btbcm serdev bluetooth ecdh_generic cfg80211 rfkill snd_soc_pcm512x_i2c snd_soc_pcm512x snd_soc_hifiberry_dacplus snd_soc_bcm2835_i2s snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd i2c_bcm2835 clk_hifiberry_dacpro uio_pdrv_genirq uio fixed ecryptfs ip_tables x_tables ipv6
[ 2497.600680] CPU: 0 PID: 4109 Comm: kworker/u8:10 Not tainted 4.14.62-v7+ #1134
[ 2497.600684] Hardware name: BCM2835
[ 2497.600943] Workqueue: btrfs-extent-refs btrfs_extent_refs_helper [btrfs]
[ 2497.600968] [<8010ffd8>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24)
[ 2497.600977] [<8010c240>] (show_stack) from [<80787284>] (dump_stack+0xd4/0x118)
[ 2497.600988] [<80787284>] (dump_stack) from [<8011da6c>] (__warn+0xf8/0x110)
[ 2497.600996] [<8011da6c>] (__warn) from [<8011dacc>] (warn_slowpath_fmt+0x48/0x50)
[ 2497.601232] [<8011dacc>] (warn_slowpath_fmt) from [<7f4ffb44>] (btrfs_run_delayed_refs+0x2ec/0x318 [btrfs])
[ 2497.601712] [<7f4ffb44>] (btrfs_run_delayed_refs [btrfs]) from [<7f4ffc24>] (delayed_ref_async_start+0xb4/0xc0 [btrfs])
[ 2497.602174] [<7f4ffc24>] (delayed_ref_async_start [btrfs]) from [<7f556c54>] (normal_work_helper+0xb0/0x3cc [btrfs])
[ 2497.602640] [<7f556c54>] (normal_work_helper [btrfs]) from [<7f5573f8>] (btrfs_extent_refs_helper+0x1c/0x20 [btrfs])
[ 2497.602883] [<7f5573f8>] (btrfs_extent_refs_helper [btrfs]) from [<801375b8>] (process_one_work+0x158/0x454)
[ 2497.602893] [<801375b8>] (process_one_work) from [<80137918>] (worker_thread+0x64/0x5b8)
[ 2497.602902] [<80137918>] (worker_thread) from [<8013d99c>] (kthread+0x13c/0x16c)
[ 2497.602914] [<8013d99c>] (kthread) from [<8010810c>] (ret_from_fork+0x14/0x28)
[ 2497.602919] ---[ end trace ad203cb5486fa489 ]---

When I plug the drive to workstation (with oSuse, kernel 4.18.5-1-default) the disk work OK. The Rasbian kernel is 4.14.69-v7+. Do you know what might cause the issue?

[JamesH65]

We are unlikely to be able to spend any time on this, but it would be worth trying the latest kernel and reporting back.

This issue will be closed within 30 days unless further interactions are posted. If you wish this issue to remain open, please add a comment. A closed issue may be reopened if requested.

[JamesH65]

Closing due to lack of activity. Please request to be reopened if you feel this issue is still relevant.

[t460p]

how solve this issue?

[pelwell]

You could start by opening a new issue, stating clearly what the problem is.