treedown’s Report

システム管理者に巻き起こる様々な事象を読者の貴方へ報告するブログです。会社でも家庭でも"システム"に携わるすべての方の共感を目指しています。

※https化しました。その影響でしばらくリンク切れなどがあるかもしれませんが徐々に修正していきます。 リンク切れなどのお気づきの点がございましたらコメントなどでご指摘いただけますと助かります。

rsyncプロセスが終わらない=障害?

障害のような障害でないような、そんな症状に対処した記録です。
ある日、謎の動作不調が発生しました。

最近sambaサーバが遅い

「そういや、本件とは関係ありませんけど、最近、サーバの動き遅いですよね。」

ある日、別件でやり取りした際にふと水を向けられた話。サーバが遅い?

「サーバ経由で保存すると、いつもより遅いんですよ。」

うーん、サーバ経由で保存?
なんとなく、ですが、サーバというのは共有フォルダのことで、どうやらsambaサーバの共有フォルダにファイルを格納するのが遅い、ということのようでした。

調査開始

サーバの負荷が上がっている?でも心当たりないなぁ…、と思いながらサーバのプロセスをtopコマンドで確認してみました。
ん?

f:id:treedown:20220415172209p:plain
rsyncプロセスがたくさん?
CPUの数値も(90.7と)かなり上昇しています。※いつもは0.0~30.0くらいのような。

psコマンド(ps -ef)でプロセスを確認してみると、

f:id:treedown:20220415172221p:plain
※上図はpsコマンド出力結果の一部

rsyncプロセスがたくさんプロセスに表示されていることに気づきました。これって残存していちゃいけないような…。

構成

遅ればせながら、簡単に構成を。

Debianのsambaサーバで共有フォルダをホスト、samba-Aとsamba-Bの2台を同じ構成にし、2台のsambaサーバ間はrsync(rsyncd)で定期的に同期し、同一のデータを保持しています。

samba-Aではrsyncdが動作しており、samba-Bはrsyncコマンドをcronで定期実行しています。

rsyncでそれほど時間差なく(共有フォルダの)同一データを2台で保持しつつ、別のWindowsコンピュータからファイルバックアップを定期的に仕掛けて、バックアップの世代としています。
-------------------------------------------------------
  <samba-A> …→ rsync …→ <samba-B>
    ↓
    BunBackup(ファイルバックアップ)
    ↓
   <Backupサーバ>(Windows)
-------------------------------------------------------
ざっくりいうと(クラスタではないが)同一筐体のsambaサーバを2台で正系副系と稼働させrsyncで同期しつつ、ファイルベースのバックアップを別途取得している、という環境でした。

実際にユーザが参照するのはsamba-Aの共有フォルダなので、samba-Aの負荷が上がっているということになります。※前述の調査はsamba-Aで実施。

そういえば、バックアップも

これを発見した際にWindowsで動作させているバックアップのタスクも確認してみました。
タスクスケジューラで起動しているのですが、タスクスケジューラのイベントから、バックアップにとても時間が掛かっている(あるいは実行間隔が短いジョブは失敗しているものもある)ことが分かりました。

バックアップもこのような状況ということは、やはりsamba-A側の負荷が上がっている為に動作遅延が起きていると考えるのが自然なように思えました。(まだ仮説)

前のrsync同期処理やバックアップによるファイルコピーが終了するまえに、次のジョブによってrsyncの同期処理やバックアップのファイルコピーが起動して多重起動になっている、という仮説です。

いったん止めてみる

理想は前の処理をどうにかして終わらせることですが、いかんせん手探り状態だったのと動作が重くなっていたことで、いったんrsyncdを停止し、積もったrsyncプロセスをいったん終わらせることにしました。
原因となるのは、おそらく容量の大きなファイルなりフォルダが要因と思われるため、それを探し出すためにも動作が重いのは調べる際の足枷となってしまいます。

rsyncdが動作するsamba-A側で、

$ sudo /etc/init.d/rsync stop
[ ok ] Stopping rsync (via systemctl): rsync.service.

と表示され、動作中のrsyncを停止させることにしました。

停止すると、psコマンドで大量に出力された
「/usr/bin/rsync --daemon --no-detach」
のプロセスはフッと消えて、存在しなくなりました。

samba-B側のpsコマンドで
「rsync -av --delete rsync://username@samba-A:/home/backup/」
のような表記で残存していたプロセスもすべて消えてなくなりました。

いったんAbortのような状況でrsyncプロセスを停止させましたので、この後の動作が不安ではありますが、いったん原因となったファイルやフォルダを特定させるため、記録を探ってみます。

Abort後のcron履歴に

保留されていたrsyncプロセスがAbortされたことで、cronからrsyncの実行結果が送られてくることになりました。
その、rsyncの実行結果を示すcronからの手紙の末尾に

-------------------------------------------------------
sent 24,502 bytes  received 5,776,223 bytes  10,079.45 bytes/sec total size is 99,444,944,468  speedup is 17,143.54 receiving incremental file list 
-------------------------------------------------------
に続いて
-------------------------------------------------------
deleting .userbackup220400.tgz.1VMrs9 userbackup220400.tgz rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at io.c(513) [sender=3.1.2]
-------------------------------------------------------
という表記、さらに続けて
-------------------------------------------------------
rsync: failed to connect to samba-A (samba-A): Connection refused (111) rsync error: error in socket IO (code 10) at clientserver.c(127) [Receiver=3.1.3]
rsync: failed to connect to samba-A (samba-A): Connection refused (111) rsync error: error in socket IO (code 10) at clientserver.c(127) [Receiver=3.1.3]
…(以下同じ表記が続く)
-------------------------------------------------------
となっていました。

どうやらこの「userbackup220400.tgz」というファイル名(※このファイル名は仮名です。)が原因で、rsyncの同期や、バックアップのファイルコピーなどが阻害されていたような感じがします。
「sudo find /home/ -name userbackup220400.tgz」
でファイルの格納されたパスを探し出して、実際のファイルを確認してみると、

f:id:treedown:20220415171931p:plain
ああ…、容量大きいですね。ひとまず、このファイルをバックアップ用のWindowsで回収して、サーバの共有フォルダから除いてジョブを再開させてみますか。

正常化

容量の大きなファイルを除いて再度samba-A側のrsyncdを再開しました。

$ sudo /etc/init.d/rsync start

再開後のtopコマンドの実行結果では

f:id:treedown:20220415171955p:plain
CPUの使用率が2.7と低負荷に収まっています。samba-B側のcron実行結果を見ていると、最初は(障害で保留されていたファイルの同期が一気に動作したので)かなりの数だけファイル同期が動作していましたが、時間のかかっていたのはその初回のみで、ほどなく通常運転に戻ったようでした。

ひとまず、経過観察となりますが、どうやら無事元の状態に戻ってくれたようです。バックアップもジョブを停止してやり直し(まだやっていない)すれば、戻ると思いますので、これで対処完了となりました。