어느 날부터 Hyper Backup이 실패합니다.
하루에 한 번씩 백업을 합니다. 10개월 정도 사용했는데요. 문제가 발생한 경우가 한 번도 없습니다. 그러다가 어느 날부터 갑자기 백업이 실패합니다. 백업을 시작하자마자 백업이 중단되는게 아니라 50분 정도 백업을 진행하다가 중단됩니다.
예약된 백업시간이 되면 정상적으로 백업을 시작하지만 50분 정도 진행하다가 중단됩니다.
02시에 백업을 시작하고 03시에 가까워지면 백업이 중단됩니다. 하이퍼 백업 로그에는 다음과 같은 로그가 생성됩니다. 실패했다는 내용 말고는 아무런 단서가 없습니다.
Error 2023/02/01 02:55:16 SYSTEM [Network][xxxx] Failed to run backup task.
Error 2023/02/01 02:54:58 SYSTEM [Network][xxxx] Exception occurred while backing up data.
Information 2023/02/01 02:00:02 SYSTEM [Network][xxxx] Backup task started.
소요시간 : 1시간 어려움 : ★★★★★
용량이 비정상적으로 큰 파일을 삭제합니다.
백업 소스에 PB(1024TB) 단위 크기의 파일이 들어있습니다. 백업을 진행하다가 이 파일을 맞닥뜨리면(아마도 백업을 50분 정도 진행하면 이 파일을 백업할 차례가 되는 것 같음) 백업 프로세스가 중단되는 것으로 추측됩니다.
로그 센터에서 이 파일을 생성한 컴퓨터와 사용자를 찾을 수 있습니다. 그 사용자에게 어떤 프로그램으로 어떤 작업을 했는지 물어보면 터무니없는 크기의 이 파일이 왜 생겼는지 알 수 있지만, 나스에 원격으로 접속해서 작업을 하다보니 물어보지 못했습니다. 개인적으로 매우 궁금하기는 합니다. 이 파일을 삭제하고 나서는 하이퍼 백업이 정상적으로 작동합니다.
27.5PB 크기의 파일이 존재합니다. 디스크에 기록된 부분은 8MB 밖에 되지 않습니다. 이 파일의 생성 날짜가 하이퍼 백업이 실패하는 날짜와 일치합니다.
문제의 파일은 파일 스테이션에서도 확인이 됩니다.
root@NAS:~# ls -alS -rwx------+ 1 user users 31027466529768398 Jan 27 14:35 xxxx.wmv
~생략~ root@NAS:~# ls -alSh -rwx------+ 1 user users 28P Jan 27 14:35 xxxx.wmv
~생락~
문제의 파일은 터미널에서도 확인이 됩니다.
PB 크기의 파일을 삭제한 이후에는 하이퍼 백업이 정상적으로 완료됩니다.
궁금하면 ↓↓↓↓
하이퍼 백업에서 발생한 오류 내용이 /var/log/messages 파일에 기록되어 있습니다. 하이퍼 백업이 실패한 시간대의 내용에 PB 크기의 파일이름이 나옵니다.
root@NAS:/var/log# tail messages -n 60
2023-02-02T13:38:55+09:00 NAS kernel: [15176295.922137] fsnotify get overflow, max queue size is 16384
2023-02-02T13:39:47+09:00 NAS kernel: [15176347.786679] fsnotify get overflow, max queue size is 16384
2023-02-02T13:41:08+09:00 NAS kernel: [15176428.459370] fsnotify get overflow, max queue size is 16384
2023-02-02T13:41:41+09:00 NAS kernel: [15176461.669320] fsnotify get overflow, max queue size is 16384
2023-02-02T13:44:04+09:00 NAS kernel: [15176604.879235] fsnotify get overflow, max queue size is 16384
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_helper.cpp:356 BUG: bad parameters: -271241793
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1216 failed to init candidate list
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:268 failed to start chunking file: [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:152 failed to trigger next event [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:899 failed to add meta for file [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1601 failed to start backup for [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1622 blRetor occurred: stop backup: [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:33+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:812 [CWorker] failed to start next file/dir: [/volume1/@sharesnap/XXXX/GMT+09-2023.02.02-12.04.47/A/B/C/XXXX.wmv]
2023-02-02T13:50:46+09:00 NAS img_worker[4613]: (4613) local_client_worker.cpp:472 not resumable ==> just leave (e.g. don't wait cloud uploader to saving it's queue.)
2023-02-02T13:50:46+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1904 [CWorker] error occurs, stop the worker
2023-02-02T13:50:46+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1923 [CWorker] error occurs to handle controller packet
2023-02-02T13:50:46+09:00 NAS img_worker[4613]: (4613) client_worker.cpp:1879 failed to handle controller request
~생략~ 
