USB 디스크로 파일을 전송하는 동안 Rsync가 중단됩니다.

USB 디스크로 파일을 전송하는 동안 Rsync가 중단됩니다.

rsync를 사용하여 외부 USB3 디스크(dmcrypt/luks를 사용하여 암호화됨)에 데이터를 백업하고 있습니다. 문제는 전송이 파일에서 중단되어 몇 초에서 몇 분 정도 지속되다가 오류나 오류 없이 작동한다는 것입니다. 문제. 이는 동일한 rsync "세션" 동안 여러 파일(분명히 무작위로)에서 발생하므로 일부 파일 전송은 100MB/s에 도달할 수 있지만 속도가 매우 느려집니다.

저는 Debian Jessie 8.5 rsync버전 3.1.1을 실행하고 있고 소스 파일 시스템은 btrfs(버전 3.17)로 포맷되었으며 외부 디스크는 crypsetup1.6.6으로 암호화되었습니다.
암호화된 파티션은 btrfs로 포맷되었지만 문제를 발견하고 이것이 분명히 관련이 없음을 확인한 후우분투 오류, 파티션을 ext4로 다시 포맷했는데 이로 인해 문제가 덜 자주 발생하는 것처럼 보였지만 문제는 여전히 지속됩니다.

이러한 "중지" 동안 이상한 CPU 또는 메모리 사용량은 감지되지 않지만 디스크 읽기 및 쓰기는 0으로 떨어집니다. 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정지 중 하나의 출력입니다(외부 디스크는 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은 디스크 읽기 및 쓰기를 0 위치로 표시합니다). 다시 업데이트가 시작됩니다. 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

답변2

결과 없이 많은 테스트를 거친 후 @derobert의 조언을 따르고 커널과 btrfs-progs를 최신 버전의 jessie-backports로 업그레이드하기로 결정했습니다. 새 커널( )을 사용하면 rsync 전송 중에 정지를 감지할 수 없기
때문에 문제가 해결된 것 같습니다 . 4.6.4-1~bpo8+1이제 btrfs 백포트는 4.6.1.

관련 정보