自動化してcron実行しているrsyncプロセスである日エラーが出ていたことに気づき対処を実施したのでご報告です。
現在はエラーを解消し、経過観察をしています。
エラー内容
それは数時間に一回の頻度で実施しているrsyncの実行結果を報告するメールに記載されていました。
※内容(一部抜粋)
--------------------------------------------------------------
sent 20,222 bytes received 4,639,429 bytes 64,271.05 bytes/sec total size is 697,445,397,646 speedup is 149,677.60 rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1677) [generator=3.1.3] receiving incremental file list
sent 2,847 bytes received 287,375 bytes 30,549.68 bytes/sec total size is 2,279,214,244 speedup is 7,853.35 receiving incremental file list
sent 20 bytes received 128 bytes 98.67 bytes/sec total size is 30,239 speedup is 204.32 receiving incremental file list
sent 2,621 bytes received 588,584 bytes 62,232.11 bytes/sec total size is 49,050,509,561 speedup is 82,967.01 receiving incremental file list
rsync: readlink_stat("/home/samba/Share/Documents/テストファイル.xlsx") failed: Structure needs cleaning (117)
rsync: recv_generator: failed to stat "/home/samba/Share/Documents/テストファイル.xlsx": Structure needs cleaning (117) IO error encountered -- skipping file deletion
rsync: recv_generator: mkdir "/home/samba/Share/Documents/テスト" failed: Structure needs cleaning (117)
*** Skipping any contents from this failed directory ***
--------------------------------------------------------------
通常はコピーされたファイルが羅列されているその結果リストには、「失敗しました: 構造をクリーニングする必要があります (117)」とか「IO エラーが発生しました -- ファイルの削除をスキップしています」とか「失敗しました: 構造をクリーニングする必要があります (117)
*** この失敗したディレクトリのコンテンツをスキップしています ***」という記載が見て取れました。
構成
エラーの調査に入る前に、この環境の簡単な構成図をVisioオンライン<https://www.office.com/launch/visio?auth=2>で作ってみました。
Debianにインストールしたsambaで構成されたファイルサーバは正系(FS1)と副系(FS2)の二台で通常は正系(FS1)のみがPCから参照されている状態、両方のsambaサーバではUSBハードディスクを接続し共有フォルダはすべてマウントされたUSBハードディスクに保存しています。。
この正系(FS1)側の共有フォルダのデータは日次でバックアップを取得しており、日ごとのデータは別のバックアップ用のコンピュータのディスク上に保管されます。
今回エラーが発生したのは、このFS1とFS2間で実行しているrsyncの実行で発生しました。また、エラーを出しているのはFS2側のUSBハードディスクにデータを書き込む際に発生しています。
syslog調査
syslogを確認してみたところ、cronで指定したrsyncジョブを実行している時間帯でエラーが大量に記録されていることが確認できました。
エラーは
-----------------------------------------------------------------------------------------------------------------------
EXT4-fs error (device sdc): __ext4_iget:0000: inode #00000000: comm rsync: bad extra_isize (00000 != 256)
EXT4-fs error (device sdc): ext4_lookup:0000: inode #00000000: comm rsync: deleted inode referenced: 00000000
-----------------------------------------------------------------------------------------------------------------------
概ねこの繰り返しでした。
rsyncのエラーでfailed(失敗)に続いて、「Structure needs cleaning(構造をクリーニングする必要あり)」と記載されていたり、「EXT4-fs error」の行にinodeでアドレスや「bad extra_isize」というログの記載があることで、メッセージ内容は違うものの、<Raspberry Piで問題発生? - treedown’s Report>で実施したようなファイルシステムのエラーが発生したんではないかと考えられました。
そこで、前回<Raspberry Piで問題発生? - treedown’s Report>とは違って今回はシステムドライブではない方なので、再起動を使わずにOSは起動したままでfsckを実施してみるという対処をやってみることにしました。(副系だし、バックアップ取得済だし)
fsck実行
対象のsamba(Debian)にログイン後、fsckを実行していきます。対象となるのはUSBハードディスクである「/dev/sdc」です。
早速「sudo fsck.ext4 /dev/sdc」を実行してみると、
--------------------------------
$ sudo fsck.ext4 /dev/sdc
e2fsck 1.44.5 (15-Dec-2018)
/dev/sdc is mounted.
e2fsck: Cannot continue, aborting.
--------------------------------
おっと、失敗。当然ですが、マウントしているボリュームにfsckは実行できません。
$ sudo umount /dev/sdc
を実行し、「df -h」などでマウントが解除されたことを確認して、再度fsckを実行してみます。
※umountすると当然sambaサーバサービスに影響しますので、ユーザに影響のない状況で実施する必要があります。
--------------------------------------------------------------
$ sudo fsck.ext4 /dev/sdc
e2fsck 1.44.5 (15-Dec-2018)
/dev/sdc contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Inode 56360965 has a extra size (16895) which is invalid
Fix<y>? yes
Inode 56360966 has a extra size (16895) which is invalid
Fix<y>? yes
(以下略)
--------------------------------------------------------------
おお、たくさん出てきました。途中で、
--------------------------------------------------------------
Inode 56360986 has a extra size (16895) which is invalid
Fix ('a' enables 'yes' to all) <y>? yes to all
--------------------------------------------------------------
という行が出てきたので「a」を押下し、以下は全て修復を意味する「Yes」が選択されるようになりました。途中から、
--------------------------------------------------------------
Inode 56360990 has illegal block(s). Clear? yes
Illegal block #0 (1662447826) in inode 56360990. CLEARED.
Illegal block #1 (1459337963) in inode 56360990. CLEARED.
Illegal block #2 (1379058585) in inode 56360990. CLEARED.
Illegal block #8 (1662447826) in inode 56360990. CLEARED.
Illegal block #9 (1459337963) in inode 56360990. CLEARED.
Illegal block #10 (1379058585) in inode 56360990. CLEARED.
Illegal block #94 (3975296973) in inode 56360990. CLEARED.
Illegal block #95 (1039726182) in inode 56360990. CLEARED.
Illegal block #96 (1098979632) in inode 56360990. CLEARED.
Illegal block #99 (2131169410) in inode 56360990. CLEARED.
Illegal block #101 (1762164472) in inode 56360990. CLEARED.
Too many illegal blocks in inode 56360990.
Clear inode? yes
--------------------------------------------------------------
こういうのがたくさん出てきて修復されている感じがしてきます。最終的に、
--------------------------------------------------------------
Free inodes count wrong (242786881, counted=242787025).
Fix? yes
/dev/sdc: ***** FILE SYSTEM WAS MODIFIED *****
/dev/sdc: 1400111/244187136 files (1.1% non-contiguous), 510564354/976732160 blocks
--------------------------------------------------------------
こういった表記になって完了したようでした。無事完了してくれたようです。
エラーは修復された?
こうしてエラーは修復されたような動作を見せてfsckは完了しました。
ここから、次のrsyncタスクの実行を待って、経過観察をしてみることにします。
完了後は忘れずに、アンマウントしたボリュームを再度マウントしておくことを忘れないようにします。
マウントは(例としてマウント先が</mnt/usrhdd>の場合の書式)
$ sudo mount /dev/sdc /mnt/usrhdd
と実行しておきます。umountは取り外す/dev/sdcの指定だけで良かったですが、mountはマウント先も指定する必要あり。
完了後「df -h」などで正常にマウントされたことを確認して、対処完了とします。
※後日実行されたrsyncのタスクでは無事エラーの出力は収まって、以前のようにファイルの同期が実施されているログが記録されるようになりました。