“アタリ” は諸刃の剣|SSH越しのコマンド実行でハマった

“アタリ” は諸刃の剣|SSH越しのコマンド実行でハマった

インフラ部門ではなくとも、開発メインのエンジニアにも必要不可欠になってきたSSHの基礎知識。当然ながら、私も最低限の知識は押さえて日々の業務にあたっています。

そんな中、SSHコマンドによる思わぬ落とし穴で30分ほどハマってしまいました。
具体的に言えば、プロセスが残るようなコマンドを実行させたことで、ディスク使用率が上がってしまったという問題です。

今回はその顛末をご報告しようと思います。

実行したコマンドとは

私が実行したのは「tail -f」のコマンドです。
「tail -f」はログファイルなどの追記出力をリアルタイムで監視することができる、私の業務には欠くことのできないコマンドになります。

このコマンドを実行することでファイル追記分を監視し続け、終了するにも「Ctrl+C」を押すなどするしかありません。
この「監視し続ける」行為こそがプロセス保持あってのアクションになります。

「tail -f」同様にプロセスを残してしまうコマンドとして一般的なのは「ssh-agent (※)」とかでしょうか。
(※パスフレーズの入力の手間を省く便利なコマンドですが、パスフレーズをキャッシュとして保存することになるため、ログアウト後もメモリリソースを使ってしまうもの)

とにもかくにも、今回は「ssh ~ tail -f /var/log/nginx/access.log」というコマンドを実行したことで、ログイン側にプロセスが残ってしまい、結果的にディスク使用率が上がってしまいました。

事象発覚の経緯と調査の動機

ショーケース・ティービーでは「fluentd」を使ってログ収集している箇所があります。
この「fluentd」はTreasure Data社が開発するログ収集管理ツールであり、オープンソースで公開されていることからプラグイン自体も豊富に用意されています。

弊社ではこれまでも専用のプラグインを書いて運用していましたが、今回はこのプラグインに軽微な改修を入れたこともあり、確認用として問題のコマンド「ssh ~ tail -f /var/log/nginx/access.log」を実行することにしました。

時系列にすれば、以下のような感じです。

  1. 「fluentd」のプラグインを改修
  2. プラグインの確認用にフロントサーバ1のログをSSH越しに「tail -f」コマンド実行
  3. プラグインのテストをしばらく実施
  4. フロントサーバ1のディスク使用率が他に比べて大きいことに気付く(!)

今回はあくまでもテストということで、フロントサーバ郡の中からフロントサーバ1だけを対象に実行しました。

まず、対象としたサーバは「Amazon EC2」。
元々ディスク使用率が少なかったのですが、今回のテストによりフロントサーバ1だけ使用率が急上昇。さすがにおかしいということで調査に至ったのです。

私が実施した調査手順、そして見当を付けることの難しさ

  • 問題のフロントサーバ1と正常なフロントサーバ2で比較
    1. 「df -h」を実施
      • ディスク使用率が倍ほど異なることを確認
    2. 「/」にて「du -h –max-depth 1」を実施
      • ほぼ差がないことを確認
    3. 「lsof」でサイズを確認
      • 倍ほど差が出ることを確認
    4. 該当プロセスに見当を付けて確認
      • 「nginx」「ruby」「php」では問題がないことを確認
    5. 他に考えられないのでlsof全体からそれぞれのプロセス名でgrep
      • 「ssh ~ tail /var/log/nginx/access.log」のnginxに問題と思しきプロセスを引っかかり発見

プロセスが掴みっぱなしになっているという状態はすぐに把握できたですが、困難を極めたのは該当のプロセスを見つけることですね。
上記の調査フローにおいて、まず先に「lsof (※)」コマンドでファイルサイズ順に並べて調査することをスキップしてしまったことが困難を極めた要因です。
(※開いたファイルのプロセスを特定するコマンド)

サーバでアプリケーション用に動かしているプロセスが「nginx」「td-agent」「php-fpm」だけということもあり、この3つさえ調べておけば済むものだという先入観を持ってしまいました。
しかし、今回は “SSH越し” であることを完全失念。
“SSH越し” という状況でプロセスを残すようなコマンドを実行しているのであれば、アプリケーションプロセス3つだけの調査で済むワケがないですよね。

素直に「lsof」コマンドを実行し、ファイルサイズ別にソートをかけてしまえば、どんなプロセスが大きなファイルを掴んでいるのかを判断でき、すぐに解決したのかもしれません。
しかし、この先入観が若干発見が遅らせてしまいました。。。

あらかじめ見当を付けるという行為自体は、作業効率化の観点から言えば間違っていません。
同じ「lsof」コマンドを実施するにも、ある程度の見当を付けてディレクトリを指定することで、ファイル全体をイチから調査することよりも煩わしさも軽減するためです。
しかし、この “見当を付ける” 行為は慎重にしないと、かえって手間を生んでしまうというワケですね。

で、どうしてプロセスが残ったの?

正直なところ、どうして「ssh ~ tail -f /var/log/nginx/access.log」が残ってしまっていたのかは未だに分かっていません。
しかし、監視終了するための「Ctrl+C」を実行しさえすれば、プロセス自体も消えることは確認してます。

ただ、原因究明に至っていないモヤモヤは残ってしまいましたね……。
とはいえ、都度発生する面倒はまっぴらゴメン。
この苦労を頭の片隅に置いておくことこそが、作業の効率化に役立つことなのかもしれませんね。

コメント