Dotaz: Zamrzá rsync

[Skeletonix]

Dobrý den / Ahoj,

pro zálohu domovského adresáře prac. stanice (openSuse Tumbleweed) používám externí disk připojený k Raspberry (Rasbian), synchronizace dat je realizována pomocí rsync. Externí disk je šifrovaný pomocí LUKS, na disku je BTRFS s aktivovanou kompresí a průběžně se tam dělají snapshoty (snapper).

V poslední době se mi začal objevovat problém se zápisem na externí disk, rsync po chvilce zamrzne a v dmesg (na Raspberry) se objevuje:

[40671.388839] INFO: task btrfs-transacti:1572 blocked for more than 120 seconds.
[40671.388850]       Not tainted 4.14.62-v7+ #1134
[40671.388853] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[40671.388859] btrfs-transacti D    0  1572      2 0x00000000
[40671.388890] [<8079d258>] (__schedule) from [<8079d8c0>] (schedule+0x50/0xa8)
[40671.389204] [<8079d8c0>] (schedule) from [<7f4b6878>] (btrfs_start_ordered_extent+0x128/0x158 [btrfs])
[40671.389687] [<7f4b6878>] (btrfs_start_ordered_extent [btrfs]) from [<7f4b6e20>] (btrfs_wait_ordered_range+0x140/0x18c [btrfs])
[40671.390153] [<7f4b6e20>] (btrfs_wait_ordered_range [btrfs]) from [<7f4e93c4>] (__btrfs_wait_cache_io+0x50/0x1e4 [btrfs])
[40671.390620] [<7f4e93c4>] (__btrfs_wait_cache_io [btrfs]) from [<7f4ebe3c>] (btrfs_wait_cache_io+0x40/0x48 [btrfs])
[40671.391081] [<7f4ebe3c>] (btrfs_wait_cache_io [btrfs]) from [<7f47f48c>] (btrfs_start_dirty_block_groups+0x170/0x41c [btrfs])
[40671.391542] [<7f47f48c>] (btrfs_start_dirty_block_groups [btrfs]) from [<7f492f70>] (btrfs_commit_transaction+0x154/0xc2c [btrfs])
[40671.392005] [<7f492f70>] (btrfs_commit_transaction [btrfs]) from [<7f48e12c>] (transaction_kthread+0x1b4/0x1c8 [btrfs])
[40671.392243] [<7f48e12c>] (transaction_kthread [btrfs]) from [<8013d99c>] (kthread+0x13c/0x16c)
[40671.392254] [<8013d99c>] (kthread) from [<8010810c>] (ret_from_fork+0x14/0x28)

Příkaz na zálohování:

rsync --log-file=/home/user/backup_home.log -av -e '/usr/bin/ssh' --delete --exclude-from=/home/user/backup_home_exclude_list.txt /home/user/ user@10.0.0.2:/media/backup/User/Home/

Zálohu rootu provádím pomocí taru, ukládá se na shodný subvolume jako záloha home a to funguje bez problémů. Příkaz pro zálohu je:

ionice -c2 -n7 tar -cvpz --exclude=/mnt --exclude=/media --exclude=/tmp --exclude=/home --exclude=/proc --exclude=/sys --exclude=/dev --exclude=/run --one-file-system / | ssh user@10.0.0.2 "( ionice -c2 -n7 cat > /media/backup/User/System/$file$datum.tar.gz )"

Vypadá to, že se problém projevuje jen při užití rsyncu.

Měl jsem podezření, že je vadný disk či FS, ale když externí disk připojím k prac. stanici a zálohu udělám lokálně, tak vše projde ok.

Nevíte proč mi rsync po chvíli spadne a způsobí prakticky nedostupnost celého subvolumu? Jediné co pomůže je restartovat Raspberry.

Odpovědi

[Josef Kufner]

Koukni na spotřebu paměti. Nenaroste během zálohování příliš? Nedávno jsem s BTRFS narazil, že při použití snapshotů a kvót sežral spoustu paměti a serveru prostě došla. Paměť použitá BTRFS se navíc neodswapuje, takže to vypadalo docela podivně – žádná volná paměť, prázdný swap a závratný load. Když jsem pak chtěl pár snapshotů smazat, tak bylo po zábavě úplně. Vypnul jsem kvóty a teď mám půlku paměti volnou. Jen nevím, kolik která záloha zabírá místa.

[Skeletonix]

Spotřeba paměti se zdá být Ok a navíc tar funguje korektně. Pokud by bylo nedostakem paměti, tak by to mělo dopad i na tar, ne? Kvóty na disku nastavený nemám.

Vyzkoušel jsem kopírování přes rsync lokálně na Raspberry (abych ověřil, že není na vině ssh nebo něco na síti) a to při kopírování více menších souborů vedlo k chybě:

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 ]---

a mountpoint se stal read-only.

Raspberry jsem restartoval a začaly se objevovat hlášky:

[  356.021486] BTRFS: error (device dm-0) in btrfs_run_delayed_refs:3089: errno=-17 Object already exists
[  356.037496] BTRFS error (device dm-0): pending csums is 16515072
[  376.512426] BTRFS error (device dm-0): parent transid verify failed on 4368029679616 wanted 297300 found 261640
[  376.512462] BTRFS info (device dm-0): no csum found for inode 1570317 start 51380224
[  376.514838] BTRFS error (device dm-0): parent transid verify failed on 4368029679616 wanted 297300 found 261640
[  376.514866] BTRFS info (device dm-0): no csum found for inode 1570317 start 51380224
[  376.516757] BTRFS error (device dm-0): parent transid verify failed on 4368029679616 wanted 297300 found 261640
[  376.516788] BTRFS info (device dm-0): no csum found for inode 1570317 start 51380224

Zvláštní je, že to zlobí jen na Raspberry, pokud disk připojím k oSuse, tak žádné problémy nepozoruji.

[Josef Kufner]

Nemáš na Raspberry výrazně starší jádro než na tom Suse? Možná jsi našel starý a opravený bug v BTRFS driveru.

[Skeletonix]

Rozdíl tam je, Suse 4.18.5-1 a Rasbian 4.14.-62. Přes rok tato konfigurace fungovala dobře, začalo to zlobit před časem.

[Josef Kufner]

Koukni, jaké chyby se od té doby opravily. Zkusil bych upgrade, možná jsi nějakou našel.

[Skeletonix]

Mám nainstalovaný poslední kernel z repositáře Raspbianu. Novější verzi bych musel kompilovat, deb balíček jsem nenašel.

[MM]

Zkontroluj ještě napájení - má ext. disk svoje? Nebo se napájí z raspberry?

[Skeletonix]

Tam bych problém neočekával, disk má svoje napájení. Při připojení k prac. stanici napájení neměním a tam disk funguje ok.