とある新人のブラック就労記　その１５

2019年3月1日

新システム導入日から三日。

この日が何事もなく終了すればシステムは安定稼働したということになり、現場組は現場から撤退し会社に戻ってくる。
初日以降、朝８時から夜１０時頃まで、リソース監視とデータ集計と分析（一日のトラフィック量やデータベースの統計情報の解析など）を行っていた新人くんだが、システム導入が滞りなく終了すれば明日から平常出勤（９時１７時）に戻れることになっていた。

「手を抜いたときに限ってトラブルが起きる。今日ぐらい早く帰ってもいい、そう思ったときに限って帰った直後にトラブルが起きる。システムってのは、そういうものだ」

鈴木さんの口癖だ。

「チェックは絶対にする。確認は怠らない。承認を貰うことも、連絡をすることも、必ずやる。一つでも抜けると、そこからほころびる」

ともすれば仕事をする上で当たり前ともとれる心構え。ただ、長く働けば働くほど、慣れれば慣れるほど「まぁ、今回くらいいいや」という魔の手を引き寄せる。

しかし、それでも。

気を抜かず、驕らず、万端の準備をしていたとしても、トラブルは必ず起きる。

――ピロリロリーン。ピロリロリーン。

社内に会社携帯のメール音が鳴り響く。音の方向は、運用部のデスクからだった。
携帯キャリアーのデフォルト音。間の抜けた音。
しかし、それはトラブル発生の合図だった。

『新人、鈴木、お前らのプロジェクトで使っているサーバからのメール発信だ。アプリサーバが停止したらしい』

運用部の藤堂さんからの内線。サーバに設定された異常を検知した際に自動送信されるメールだった。
時刻は午後二時。もちろんユーザーがシステムを使っている時間帯だ。となると、現場でも騒ぎが発生している可能性が非常に高い。
すぐさま、新人くんと鈴木さんは藤堂さんと一緒に専用デスクに移り、サーバにアクセスした。
藤堂さんが同席するのは、既にシステムが稼働しているため開発部だけでなく運用部の案件でもあるからだ。
システム導入時期は試用運用も含めているため、運用部が後々の運用保守フェーズでのノウハウ蓄積のために同席することが多かった。

鈴木さんがサーバにログインすると同時に、現場からも電話がかかる。

『ブラウザがタイムアウトするんだけど』

長谷さんからの連絡だった。
鈴木さんは電話をしながらキーボードをたたいて現状を確認する。
・サーバは生きている。
・サーバの上で走らせているアプリサーバがフリーズしている。
・サーバのレスポンスが非常に遅い。

Ping確認、TOP確認……リソースの確認をするが、アプリサーバのタスクがCPU100%となっているだけで、他に原因が見当たらなかった。
鈴木さんはアプリサーバがまともに動いていないことを確認した後、アプリサーバを強制終了し、サーバのリソースを解放した。

「……新人はログを確認してくれ。俺は現場組から状況をヒアリングする」

アプリサーバが吐き出しているログを優先的に、新人くんはログを確認した。
このプロジェクトで開発したWebシステムは致命的な例外（いわゆるぬるぽなど）は詳細にログを出力するよう設定されていた。
そのため、なにかシステム上問題があればログに出力されるはずだった――が。

「んー、容量みればわかるが、ログにはエラー吐かれてないみたいだな」

電話をし終わった鈴木さんがサーバ上にあるログファイルの詳細リストを見てこぼす。
エラーログは別途別ファイルで出力するように設定されているため、エラーが無い場合は0kbのまま。また、日々吐いている処理の簡易ログも流し見したが、昨日までのリソースチェックから変わった様子はなかった。

「現場は昨日と同じ運用だったそうだ。庫内用帳票を印刷した後、５分ほど時間をおいて再度システムにログインして使用しようとしたら入れなくなっていた、と」

なにかの作業途中にエラー落ちしたわけでもなく、庫内に複数あるPCで様々な機能を使用していたため、機能の特定も難しい。

「新人、現場組から送られた作業手順書を用意してくれ」

鈴木さんが少し考え、新人くんにそう指示する。
現場組が現場でヒアリングした、システムを使用した一日の作業手順を時刻別にまとめたものを新人くんは印刷した。
朝１０時はこの機能を使用し、午後一はこの機能から始まり……といったように、大体の時間帯で使用している機能を特定することができるからだ。
もちろん、交通の遅延やその日の荷物の大小で時間が前後するので絶対ではないが、参考にはなる資料だった。

「……よし、社内の開発環境で朝から現在時刻までの現場作業をトレースをする。データを用意するぞ新人。藤堂さんは電話対応をお願いします。時間は――とりあえず一時間ください」

原因が特定できないため、『なにが原因なのか』を特定するための検証。
現場と同じデータを用意し、問題の切り分けをする。
もちろん、開発環境と本番環境のスペックの違い、使用する端末（PC)の違い、細かい手順の違いはあるものの、逆に言えばその違いを抜いた大筋に問題が無いと分かれば、今度はそのスペックの差異を突き詰めれば解決する。

なぜ止まったのか。なにが原因だったのか。
とりあえず再起動でなおった。とりあえずいらなそうなファイルを削除したらなおった。とりあえず〇〇したらなおった。
というのは、システム開発者には御法度の弁解理由だ。
トラブルが起きたら必ず原因を追究し、『二度と起こらない』という保証ができるようにする必要がある。そしてそれは、開発者や運用保守者の負担を減らすためでもある。
もし『再起動でなおった』という報告をしてしまった場合、トラブルが再発しないように『再起動をする』という作業が定期的に発生し、そのたびに再起動が正常完了したかをチェックする人員が発生し、結果的に運用コストがあがるからだ。
『再起動でなおった』の実際の原因が長時間稼働によるリソースの圧迫であれば、圧迫原因のリソースを食ってしまう処理を見直したり、サーバを停止せずにリソースを解放するタスクを設定すれば再起動しなくても済む可能性もあるにも関わらず、『理由はよく分からないが、月に一度再起動するシステム』というシステムになってしまう。そして、現在稼働している多くのシステムの中には実際にそういうシステムが存在する。

「昨日のバックアップをDBに入れて――、朝から作業を開始する。現場から送られたデータも入れ込むぞ」

実際にデータを手入力し、紙を印刷し、現場が行ったであろうPC作業をトレースする。
その間に催促の電話はかかってくるが、藤堂さんにお願いして原因究明中としていた。

そして、作業すること一時間――。

「ビンゴ、だな」

鈴木さんが実行した機能の処理の後、開発環境のサーバがハングアップした。

「ログファイル、か。あー……そういうことか」

鈴木さんが言うには、原因はログファイルによるサーバディスクの圧迫だったらしい。
もちろん、ログファイルは調べたが、そのような大容量ログファイルはなかった。
が、鈴木さんには詳細は後で、と言われ、すぐさま本番環境を対処療法――再起動とログファイル出力の抑制設定を行う。全てが完了したときにはシステム停止時間は１時間半を超えていた。
もちろんその間も現場は動いている。倉庫で働いたことはない新人くんだが、２時間近くもシステムが使えない状態、というのはまずいのではないか。そう感じていた。
胃がキリキリ痛む、というのはこういうことか――そう新人くんは実感した。

「よし、再起動OK、アプリサーバは起動できた。CPU高負荷状態も解除されてる。長谷さんに連絡する」

無事に起動することを確認した後、起動後テストを行い、現場に連絡。一時的にトラブルの対応が完了したことを伝えた。

新人くんが原因がなんだったのか聞くと、鈴木さんはため息をつきながら答えた。

「大容量のログファイルによるディスク圧迫。それも、特殊なケースの時に出力されるログだな。昨日も一昨日も、リソースチェックしたときは空き容量は大丈夫だったわけだしな。今日に限って、一度に大量のディスク容量を食うログが排出されるバグ処理が実行されてたんだ。で、限界ギリギリまでディスクを食ってアプリサーバを巻き込んで落ちた後、生成したログファイルが巻き戻って見た目上は圧迫していない、といった感じだ」

最終日に行われた業務が、今まで通らなかったプログラムのある部分を通る処理になっていて、そこが不具合を起こした結果のトラブルだった。
特に変わった業務というわけでもなく、そして使用した機能にも違いはなく、昨日まではコンニャクという商品のリストを出していたが、今日からはハンペンという商品のリストも一緒に出した。例えるならそんな程度の違いだった。

「これは外注さんのやった箇所か。はーっ、Java経験年数五年が書くコードじゃねぇだろ……」

ソースファイルを見て鈴木さんがため息をつく。

不具合箇所を簡単に解説すると、スタックトレースという例外が発生したときに出力されるログの処理が、普通の処理時にもなぜかログを出力するようにコーディングされていて、あるパターンの時に大量のログが出力されるようになっていた。
スタックトレースはもちろん、不具合発生時の原因究明に必要なため、圧縮せずテキストファイルでサーバに蓄積されるように設定してあったせいで……というのもおかしいが、そのために急激にディスク容量を圧迫するようになってしまっていた。

「本来なら、修正がきちんと完了してからサーバを開けるのが筋だが……。今日の残り作業は件の機能も使わないし、もし使う場合になったときは他の機能で代用する、だから今日の内になおしておけば運用上問題ない……っていう長谷さんの判断だ」

開発部としては、致命的なバグを抱えたままシステムを走らせることへの不安があるが、営業部としては、現場が回ることを最優先する。

「運用でカバー、ってやつだ。ま、今日緊急メンテナンスと称しての緊急リリースだな」

緊急リリースはもちろん深夜に行う。
この時、新人くんの徹夜が確定した。