rsyncを使用して外部USB3ディスク（dmcrypt / lukを使用して暗号化）にデータをバックアップしています。問題は、転送がファイルで中断され、数秒から数分続くとエラーやエラーなしで動作することです。問題。これは同じrsync "セッション"中に複数のファイル（明らかにランダムに）で発生するため、一部のファイル転送は100 MB / sに達する可能性がありますが、非常に遅くなります。
私はDebian Jessie 8.5rsyncバージョン3.1.1を実行しており、ソースファイルシステムはbtrfs（バージョン3.17）でフォーマットされており、外部ディスクはcrypsetup1.6.6で暗号化されています。
暗号化されたパーティションはbtrfsでフォーマットされていますが、問題が見つかり、これが明らかに関連していないことを確認した後Ubuntuエラー、パーティションをext4に再フォーマットしましたが、これは問題が頻繁に発生しないように見えましたが、問題は依然として続きます。
これらの「停止」の間、奇妙なCPUまたはメモリ使用量は検出されませんが、ディスクの読み書きはゼロに低下します。iotop停止中の出力は次のとおりです。
Total DISK READ : 0.00 B/s | Total DISK WRITE : 0.00 B/s
Actual DISK READ: 0.00 B/s | Actual DISK WRITE: 0.00 B/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
21879 be/4 root 0.00 B/s 0.00 B/s 0.00 % 99.00 % [kworker/6:1]
1085 be/4 root 0.00 B/s 0.00 B/s 0.00 % 99.00 % [kworker/3:2]
31994 be/4 root 0.00 B/s 0.00 B/s 0.00 % 99.00 % [kworker/4:3]
1 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % init
2 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kthreadd]
3 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [ksoftirqd/0]
5 be/0 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kworker/0:0H]
7 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcu_sched]
kworkerプロセスは常に変更されますが、99％IOを維持します。
これはiostat停止の1つの出力です（外部ディスクはsdgです）。
avg-cpu: %user %nice %system %iowait %steal %idle
0.00 0.00 0.25 99.75 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdc 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdd 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdf 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
md0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
md1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdg 0.00 0.00 0.00 141.00 0.00 16920.00 240.00 135.94 868.20 0.00 868.20 7.09 100.00
dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 20343.88 0.00 0.00 0.00 0.00 100.00
私もps aux | awk '$8 ~ /D/ { print $0 }'時計の電源を入れて走りましたが、停止中に次のような結果が出ました。
root 1080 0.1 0.0 0 0 ? D 16:23 0:00 [kworker/0:0]
root 5851 0.0 0.0 0 0 ? D 01:41 0:02 [btrfs-transacti]
root 17455 4.4 0.0 105028 5192 pts/3 D+ 14:10 6:11 rsync -avr --stats --progress --inplace --delete /data/ /media/BKP-DISK/
root 24219 0.1 0.0 0 0 ? D 15:16 0:08 [kworker/5:0]
root 31892 0.2 0.0 0 0 ? D Aug02 2:08 [usb-storage]
root 31956 0.1 0.0 0 0 ? D 15:41 0:04 [kworker/7:0]
root 31994 0.0 0.0 0 0 ? D 15:42 0:01 [kworker/4:3]
root 32100 0.1 0.0 0 0 ? D 15:52 0:03 [kworker/u16:2]
転送が正常に実行されると、次のようになります。
root 17453 4.4 0.1 105020 33304 pts/3 D+ 14:10 6:32 rsync -avr --stats --progress --inplace --delete /data/ /media/BKP-DISK/
私はアイデアと専門知識を欠いているので、この問題をさらに解決するには助けが必要です。
編集する
@derobert
USB2ポートでテストしましたが、問題が引き続き発生しました（straceログで11秒の間隔を見つけてテストを停止しました）。
最後のdmesgトレースは、外部ディスクがまだbtrfsでフォーマットされていたときであり、出力は次のようになります（多くはすべて同じです）。
INFO: task kworker/u16:21:12881 blocked for more than 120 seconds.
Not tainted 3.16.0-4-amd64 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u16:21 D ffff8807f72bfa48 0 12881 2 0x00000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
ffff8807f72bf5f0 0000000000000046 0000000000012f00 ffff88022dcfbfd8
0000000000012f00 ffff8807f72bf5f0 ffff880103b92c00 ffff88026de241f0
ffff88026de241f0 0000000000000001 0000000000000000 ffff88010c4662d8
Call Trace:
[<ffffffffa02843ef>] ? wait_current_trans.isra.20+0x9f/0xf0 [btrfs]
[<ffffffff810a7e60>] ? prepare_to_wait_event+0xf0/0xf0
[<ffffffffa0285948>] ? start_transaction+0x298/0x570 [btrfs]
[<ffffffffa028da90>] ? btrfs_finish_ordered_io+0x250/0x5c0 [btrfs]
[<ffffffffa02b2f25>] ? normal_work_helper+0xb5/0x290 [btrfs]
[<ffffffff810817c2>] ? process_one_work+0x172/0x420
[<ffffffff81081e53>] ? worker_thread+0x113/0x4f0
[<ffffffff81510d61>] ? __schedule+0x2b1/0x700
[<ffffffff81081d40>] ? rescuer_thread+0x2d0/0x2d0
[<ffffffff8108809d>] ? kthread+0xbd/0xe0
[<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
[<ffffffff81514958>] ? ret_from_fork+0x58/0x90
[<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
@roaima
rsyncを実行したので、--progress現在の転送状態を見ることができ、これが最初に問題を発見した方法です。たとえば、1GBファイルの場合、100MBで中断される可能性があり、すべての転送情報（転送されたバイト、速度など）が更新を停止していることがわかります（ここで、iotopはディスクの読み取りと書き込みをゼロ位置として表示します）。再度アップデートが開始されます。 iotop は通常の読み書き値を表示します。
@activesheetd
これはstraceログの一部です（タイムスタンプオプションを追加しました）。
29253 03:47:18 <... select resumed> ) = 1 (in [0], left {59, 999999})
29253 03:47:18 read(0, "\355\1H\347?~\0\255", 8) = 8
29251 03:47:18 select(6, [5], [4], [5], {60, 0} <unfinished ...>
29253 03:47:18 write(1, "\235\356\374|\f\230\310u\330{\7\24\3169<\255\213>\347m\335kX\350\234\253\1\226M\6#\341"..., 262144) = 262144
29253 03:47:31 select(1, [0], [], [0], {60, 0}) = 1 (in [0], left {59, 999997})
29253 03:47:31 read(0, <unfinished ...>
29251 03:47:31 <... select resumed> ) = 1 (out [4], left {47, 597230})
4行と5行の間に13秒の間隔があることがわかります。これは、一時停止後の再起動に対応します。
@Fiximan
ログオプションは、この問題に関する追加情報を提供していません。ログファイルの転送中に停止が発生するため、何も起こらなかったのと同じです（straceログにもタイムスタンプ間隔が表示されます）。
ベストアンサー1
何が起こっているのかを調べるには、次のことを試してください。
straceを実行してシステムコールと応答を分析します。
sudo strace -o strace-output.log -f <your rsync command here>
次に、strace-output.logログファイルを分析し、「man strace」で詳細を確認するか、ログファイルを私たちと共有します。
rsyncを実行するときにlsofを実行すると、どのファイルがフリーズしているかが表示されます。
sudo lsof -p <rsync PID> | grep data