antlr4を使う(2)

シーマークすずきです。

前回の続きで、antlr4が生成したパーサーソースをjavaから呼び出して、利用してみます。

■ eclipseのGradleプロジェクト作成

build.gradleは以下としました。antlr4が生成するソースをjp.co.seamark.csv.generatedパッケージに吐かれる様にします。また、構文木を捜索する方式は、リスナー方式とビジター方式がありますが、今回は、リスナー方式としました。

 

■ CSVの単純なパース

前回生成したソースのCSVBaseListenerクラスを拡張します。簡単にcsvファイルの全行をString型で受け取る方式とします。まずは、構文木の文字列形式に変換して返すだけにします。

実行すると、以下の様に前回grunでコンソール出力した結果と同じ結果が表示されました。(注意)fileToString()は割愛します。

テスト用のtest.csvは前回と同じ以下。

CSVSimpleParserの実行結果。

>AST=>(file (hdr (row (field user.name) , (field string#!user.age) , (field *omit*user.gender) \n)) (row (field suzuki) , (field 50) , (field male) \n) (row (field ange) , (field 12) , (field female) \n) (row (field seamark) , (field 20) , (field male) \n))

■ 構文木をウォークスルーしてみましょう

ParseTreeクラスをParseTreeWalkerクラスでwalk()することで、構文木の各構文ノードへのenter,とexitのリスナーイベントが呼ばれますのでメソッドをOverrideすることで自分用に処理を追加できます。

プログラムで処理する場合、構文ルール毎にexitほげほげのタイミングが分かりやすいでしょう。以前のCSV.gの文法を記述した際、構成要素はfieldというルールで各行rowが構成される、としました。fieldの構文ノードを抜けるタイミング、つまり、exitField()の関数でrowリストにfield文字列を追加していきます。先頭行のヘッダー行として、headerに、取り込みたい場合、exitHdr()のタイミングです。各CSV行の行毎のタイミングであれば、exitRow()となります。headerが空でない場合にCSVデータをheaderのラベルと一緒にMapに取り込みましょう。

■ JSON形式に変換してみる。

List<Map<String,String>> rowsに全ての行が取り込まれましたので、exitFile()をOverrideしてJSON形式に出力してみましょう。以下のメソッドを追記します。

出力結果は、以下。

もう少し考慮すれば、以前のNode.jsのcsvtojson.jsと同じ様な変換ができそうです。”string#!”や”number#!”がヘッダーに付いていれば、JSON型を文字列、数値型にするとか、”*omit*”が付いていれば、JSON出力しない、とか。残りは、後日。

antlr4を使う(1)

シーマークすずきです。

antlr4について少しメモをまとめておく。

  • antlr4とは

ANTLR (ANother Tool for Language Recognition)は強力なコンパイラコンパイラです。コンパイラとは、簡単に言えば、人が理解しやすい表現の記述から、目的に合わせてコンピュータが処理しやすい形式に変換することです。コンパイラは通常次のステップを行います。まず初めに、「元になるソースから構造を発見する」次に「目的に合わせて変換」します。後者の目的部分は、各コンパイラプログラムによって様々ですが、初めのステップは、一般的には更に次の処理に分割されます。

  1. ソースからトークン(token)に分割・分解し、トークンを発掘する(字句解析)
  2. 複数のトークンを構文に従って木構造に構造化(組み上げ)する(構文解析)

コンパイラコンパイラは、上記の字句解析と構文解析するコンパイラプログラム(別名パーサーと呼ばれています)を作成するためのコンパイラです。ANTLRを使い、構文定義(grammarファイル)を記述し、その定義に従って、つまり、grammarファイルをソースにして字句解析し構文解析するためのプログラムソースを生成してくれます。開発者は目的に応じて木構造を捜索したり、変換したりすれば良いのです。ANTLRをパーサージェネレーターと呼ぶ場合もあるようです。

  • 何ができる?

たとえば、JavaやC++のソースをパースするプログラムを作成することも可能です。他にも、日本語で「式」を定義し、それを計算するというプログラムも作成できます。”(上底 + 下底) * 高さ / 2.0”などの式の文字列をパースして、意味のある単位の「変数」や「演算子」や「括弧」のトークンに分割し、定義した優先順位でトークンを組上げて、それを順番に変数を数値変換して計算を行うための計算機プログラムを作成することもできます。

  • 使ってみる

パーサーは文法が定義できればほぼ何でも作成できます。HTML、JSONなどのデータファイルをパースするプログラムも面白いですが、ここでは、簡単なcsvのパーサーを作成してみましょう。まず初めに文法定義をします。以下に簡単なcsvのantlr4の文法定義です。CSV.gとファイル名を付けます。

CSVファイルの構造の定義をしています。CSVファイルは、ヘッダー(hdr)と複数の行(row)でできている、としています。複数個(0個以上)の行である表現は’+’が付いているからです。次に、ヘッダー(hdr)は1行(row)で構成されると定義しています。行(row)の定義です。行はフィールド(fieldがカンマ(,)で区切られて複数あること、行の終端は’\r”\n’或は’\n’である、と定義しています。’*’は0回以上の繰り返しです。定義はまだ、続きます。フィールド(field)はTEXTかSTRINGのいずれかで構成されると宣言しています。TEXTは、カンマ(,)か(’\n’)か(‘\r’)の何れでもない文字の0個以上の繰り返しです、としています。つまりTEXTは数値や英数文字も全てです。STRINGは、ダブルクオートで囲われていて、連続する2つのダブルクオートか1つのダブルクオート以外の全ての文字です。

文法定義ファイルをantlr4コマンドに以下のようにわたします。

> antlr4 CSV.g

> ls

CSV.g CSV.tokens CSVBaseListener.java
CSVLexer.java CSVLexer.tokens CSVListener.java CSVParser.java

生成されたJavaソースをjavacでコンパイルします。早速、antlr4の検証ツールgrunで試してみましょう。

> grun CSV file -tree

user.name, user.age, *omit*user.gender
suzuki,50,male
ange,12,female
seamark,20,male

Control+Dで、以下がコンソールに出力されます。

(file (hdr (row (field user.name) , (field user.age) , (field *omit*user.gender) \n)) (row (field suzuki) , (field 50) , (field male) \n) (row (field ange) , (field 12) , (field female) \n) (row (field seamark) , (field 20) , (field male) \n))

階層をGUI表示させたい場合は、-treeを-guiとします。

> grun CSV file -gui

user.name, user.age, *omit*user.gender
suzuki,50,male
ange,12,female
seamark,20,male

Control+Dで以下の画面表示がされます。

antlr4_parse_tree_1

  • 今後

次回は、grunを使わずに、javaプログラムからantlr4で生成したソースを呼び出して利用してみます。

 

csvからjsonへ変換する(メモ1)

シーマークすずきです。

開発プロジェクトでいつも取り組むことのひとつが、プログラムのテストのために、テストデータを用意することです。ここでは、先日使ってみたcsvtojsonというライブラリがよく出来ていたので、簡単に紹介します。

■テストデータの元ネタはCSVで作っとく

テストデータをプログラマーが書くことは良くありますよね。入力データと結果期待値データ。プログラムに喰わせる訳ですから、プログラムが読み易いフォーマットが良いのですが、お客さんにレビューしてもらう都合上、お客さんには表計算ソフトの書式で出したいことが良くあります。そこでよく利用されるのはcsv書式です。

■csvtojsonが便利

先日も参加している開発チーム内で、テストプログラムを開発している担当者側はJSONで欲しい。テスト仕様書作成担当者は、表計算ソフトで作成中です、っと。つまり、どっかで誰かが、csvからjsonに変換する必要が発生しました。csvは構造を持たないフラット構造ですが、jsonは構造を持つための階層構造。ネットで少し調べていたら、 node.jsのライブラリでcsvtojsonがよく出来ていそうだったので、使ってみました。

参考URL: https://github.com/Keyang/node-csvtojson

■インストール

上記URLからgit cloneして利用できます。または、 npmでインストール可能です。

>npm install -g csvtojson

■動かしてみる

csvファイルのサンプルは以下のsample.csvです。

$ cat sample.csv
user.name, user.age, user.gender
suzuki,50,male
ange,12,female
seamark,20,male

変換してみましょう。

$ bin/csvtojson < sample.csv
[
{“user”:{“name”:”suzuki”,”age”:50,”gender”:”male”}}
,
{“user”:{“name”:”ange”,”age”:12,”gender”:”female”}}
,
{“user”:{“name”:”seamark”,”age”:20,”gender”:”male”}}

]

とっても簡単です。出力したくない列には、*omit* を指定すれば、jsonに変換しません。

$ cat sample.csv
user.name, user.age, *omit*user.gender
suzuki,50,male
ange,12,female
seamark,20,male

*omit*指定したuser.gender列は以下の通り変換されません。

$ bin/csvtojson < sample.csv
[
{“user”:{“name”:”suzuki”,”age”:50}}
,
{“user”:{“name”:”ange”,”age”:12}}
,
{“user”:{“name”:”seamark”,”age”:20}}

]

これのおかげで、テスト仕様書をレビュー後、直ぐにjson変換ができました。

性能診断分析サービス事例 その3

シーマークすずきです.

最近,つけ麺にハマっています.自分的には約7年周期でつけ麺がマイブームになる,という事実...

さて,性能診断分析サービスの事例,第3段となります.今回は,性能向上です.

■サイト利用者から「ページが遅い」の声

あるコンシューマ向けWebサイトを運営しているお客様の事例です.その会社の事業部の責任者は,「ページが遅い」というサイト利用者からの意見が多くなってきていることを課題の一つとして認識していました.実際に,自分でブラウザで試してみても,時々詰まったような遅いページがあったり,特定のページが極端に遅い,という経験を実際に体感していたのです.サービス責任者としては,お客様のニーズに応えることが最も重要です.Webサイトとしてニーズに応えることに加えて,リーズナブルな応答時間内に,という性能観点の目標もあるのです.そこで,サービス責任者は「ページが遅い」というサイト利用者からの声に対して何らかの改善策を具体的に検討することになりました.

 

■暗中模索

まず,開発パートナー会社さんとインフラを提供しているインフラ会社さんに現行システムの性能向上のための施策案を検討してもらいました.しかし,開発パートナー会社さんからは,簡単に云えば「マシンが遅いからだと思う」や「DBが遅いから仕方ない」とか「デザインが重いから」という様なポイントが出てきて,インフラ会社さんからは,「アプリが遅いからどうしようもない」とか「DB側は遅いSQLが無いので問題ではない」という指摘が出てきてしまい,お客様のサービス責任者の方も困ってしまいました.「取り合えず,自分たちじゃない」という反応だったからです.現行システムを請け負っている会社としては,仕事を増やしたくないとか責任範囲外なので,ということをお客様に伝えたい気持ちがあるのでしょう.一種の自己防衛本能です.

サービス担当者は,暗闇の中で何かを探すような感じで,手がかりが分からないままに「手探り」状態でなんとかして問題を解決しなければなりません.そんな文字通り暗中模索の頃にお客様からご連絡を頂きました.

 

■まずは現状把握

まずは状況を正確に把握しなければ,対策案もでてきません.そこで性能診断分析サービスのアプリケーションの挙動を数値で計測する技術が活きてきます.本番環境で数値で計測した結果は何よりも説得力があります.仮に改善内容の方法にアプリの改修が絡んだ場合でも,開発パートナー会社さんも計測した数値で説明すると,「なるほど,これは改修の効果が期待できますね」ということでご納得してタスク化してもらえます.逆に,開発会社様からは,「本番サービス環境下では,このメソッドがこんなに時間がかかっているのですね.意外だなぁ.」と新たな発見をしてもらえることもあります.ともかく,本番サービス環境のアプリケーションの挙動を数値で計測することから作業を開始しました.

 

■課題は何か?

次は,課題は何か?です.お客様のWebサイトにはたくさんのメニューやコーナーがあります.まずは,そのメニューやコーナー事に時間毎応答回数や平均応答時間をまとめました.予めお客様から頂いていた,このWebサイト内のビジネス上の重要度が高いメニューやコーナー,重要シナリオ(ページ遷移)と見比べてみると,課題が明確になってきました.どうやら,以下の2つが優先的に対処すべき課題でした.

  • 検索メニューの応答性能が10秒以上になることが多々ある.
  • お申し込みメニューの平均応答時間が遅い.

サイト全体のプログラムを分析するのはそれはそれで時間と手間がかかりますが,ある程度絞って注力することで,深い診断と分析が可能となり,結果としてスピーディに成果を得ることができます.

お客様と相談し,改めて今回の課題に対する目標は,

  • 検索メニューの応答性能が悪化する原因を特定し,対策案を検討し,提案する.目標は平均処理時間30%短縮.
  • お申し込みメニューの平均応答時間を20%短縮.

となりました.

■処理内容の詳細分析

本番サービス環境で実際に稼動しているアプリーケーションの稼動状況を映し出すことにより,様々なことがわかってきます.

まずは,「検索メニュー」の方のリクエスト状況の分析です.特に,平均応答時間だけで見ているとスパイクして遅い応答リクエストが見えにくくなります.つまり,リクエスト回数が多いサイトでは,リクエスト数である分母が非常に大きいため,平均することで,時々発生している遅いリクエストが見えなくなってしまいます.性能診断分析チームが分析する際には,「平均値とは丸められた値である」ということを強く意識し,その計測区間の最大値(その計測区間内で一番遅かったリクエスト応答時間)も一緒にプロットするようにします(下図).こうすることで,実態が見えてきます.実際には10秒以上の応答時間だったリクエストは多発していることがハッキリしました.

 

更に,一回の検索リクエストの処理内容の内訳を以下の様に横軸が時間の図化することで,どのような処理に時間がかかっているのかが分かります.

この見える化は強力です.ここの事例とは別のお客様の例では,Webの1ページの画面を処理するために,アプリケーションから同等SQLが300回実行されている実態がこの図化によって明らかになったこともありました.一回のSQLが50ミリ秒だとしても,300回×50ミリ秒で15000ミリ秒,つまり,15秒です.しかも,よくよく分析してみると実は,1回のSQLで十分だったいうことがありました.既存のDAOコンポーネントを部品化した開発を行い,ループ中からDAOを呼出す作りだったのです.SQLは”表”で結果が取れるにもかかわらず...インフラ側のDB管理者は遅いSQLはチェックしていることが多いですが,流石に1アクセスの処理で大量にSQLを発行しているのか,複数リクエストにより1発づつ発行されているかは意識していません.

さて,話を戻します.図中のsearch()が横に細い時は全く問題ありません.しかし,横に長くなるケース,要は,処理時間が延びてくる現象が確認されました.塵も積もれば山となります.図から推察するに,search()はループ中で必要な処理回数呼ばれる様です.図では80回前後呼び出されている絵です.search()メソッドが10ミリ秒なのか20ミリ秒なのかは,高々10ミリ秒の差ですが,比率では2倍の差になります.つまり,大量に発行されている場合は,全体が3秒だった処理が2倍の6秒になる訳です.しかもその呼出回数が多数であるならば,さらに時間がかかります.遅くなっている原因は,カットオーバー後,取り扱いデータ量が増え,search()メソッドが順次遅くなってきているためでした.開発側と相談し,該当ソース箇所をレビューした結果「四重ループ」が確認されました.

 

■多重ループに注意

プログラムでループ処理を書くことは簡単です.もちろん,ループ処理の中でループを書くこともできます.更に,一番内側の処理で別のメソッドを呼出し,呼出したメソッドの中で別のループを実装する.簡略化すると以下の様なコードでした.

※実際のコードはもちろん,もっと処理内容があります.

このsomeMethod()メソッドのコードは四重ループです.二重ループの内側で二重ループを持つメソッドを呼び出しているのです.性能的に危険なループです.経験豊富なプログラムならば臭うことでしょう.

上の簡略ソースの変数outer,innerのいずれも10ならば1ミリ秒以下.あっという間です.

outer,innerいずれも100として,私の作業PC上でsomeMethod()メソッドの応答時間は50ミリ秒程度でした.これも問題ないです.

outer=100,inner=1000ならば,6秒程度.ちょっと遅い.

outer,innerいずれも1000になれば,10分は返ってきません.しかも,その間ハードウェア的に1コアはCPU100%になります.

そもそも変数outerやinnerが10000になる可能性があるならば,設計段階で実現不能なロジックとして除外しなければなりません.ブラウザーで検索ボタンを押してから,10分待っている利用者はいないでしょうから,outer/innerが1000でもWebアプリケーションとしては既に現実的とは云えないでしょう.

少し脱線しますが,forループやwhileループとして見えないループもあります.再帰呼出です.再帰呼出で有名なフィボナッチ数列を例にします.

フィボナッチ数列のJavaプログラムは,以下の様な再帰呼出が典型的な実装コードです.

さて,質問です.Nがいくつぐらいまでが現実的でしょうか?最近の高速なCPUを搭載したマシンでもN=50でfibonacci()関数は現実的な時間で終了しません.高々N=50です.forループは1個しか見えないのに.

話しを戻します.多重ループは指数的に処理時間が延びることを理解しなければなりません.事例では,四重ループの内側の処理効率を見直して改善することで劇的に応答時間が改善しました.

■チューニングの鉄則

プログラムをチューニングする際の鉄則は,チューニング効果の高い箇所から手を入れる,ことです.例えば,全体が10秒のリクエストであれば,その処理時間の内訳が大きい箇所をチューニングするのが効果を得やすい訳です.元々1秒しかかかっていないメソッドを一生懸命チューニングして処理時間を半分にしても,0.5秒しか短縮できませんが,元々8秒かかっている場所を半分にできれば,4秒の短縮なのです.

性能診断分析サービスの性能向上を目的とした現場の場合は,「もっとも少ない工数で,もっとも高い効果」が得られる対策案を提案しなければなりません.そのためには,どうしても本番サービス環境でアプリケーションの挙動を数値で計測する必要があったのです.

 

■もうひとつの課題

「お申込みメニューの20%短縮」の方です.Webサイトの場合,検索して,購入する,又は,申し込みをする,ことが一般的です.利用者に検索してもらうのは,次のアクションとして購入や申し込みをしてもらうためです.一般にWebサイトの最重要機能は「申し込み」と云っても過言ではないでしょう.注文も申し込みの一種です.最近だと「申し込み」の後に「共有」することも大切な機能になってきているようです.つまり,SNSなどに購入した事をツブヤき,お友達と買った事実を共有するという機能です.このサイトは共有はありませんでしたが,「申し込み」機能は重要な機能でした.直接,売上に影響するトランザクションです.この画面遷移を詳細にモニターしました.

申し込みの一連のリクエストの前後で大量のXMLファイルのI/OとXMLパース処理が見つかりました.開発会社様に確認すると,マーケティングデータの収集のための処理でした.それにしても,ファイルから都度読みだしているし,しかも,XMLパースを毎度行っています.その後,更にバックエンドにXML電文を作成し,http通信でそのXMLを数回投げています.応答もXML形式で返ってきて,その返信をパースして解釈後,ログ記録用XMLを作成してログ出力していました.

ディスクからの読みだしはOSキャッシュに載れば性能はある程度確保できますが,ディスクへの出力は極力避けたい訳です.詳しく出力ファイルの場所を確認すると,悪い事に,NFS上への出力でした.高負荷でないWebサイトなら特に問題ではありません.しかし,高負荷サイトの場合は気にしなければなりません.複数台のWEBアプリケーションサーバが水平分散できないからです.また,NFSサーバの障害で,全てのWEBアプリケーションサーバに影響をおよぶことも問題なのです.言い換えれば,ビジネスの停止になってしまうリスクがあるからです.

以下に挙げる2つの主な対策案を提示しました.

1)WEBアプリのファイル出力はローカルファイルへ.

開発会社とインフラ会社が別々だと,インフラ会社さんの運用の手間が楽な方の設定にされてしまうことがあります.設定ファイルの変更で入力パスを変更可能な場合,多くの場合は,一か所の変更で反映できる,という理由からNFS上に置かれる事が多々あります.性能的な観点は全く考慮されません.入力ファイルはNFS上に置き,出力ファイルはローカルディスクに設定変更を提案しました.

2)キャッシュの利用

バックエンドに数回投げているXMLのうち,数回は履歴を紹介する電文でした.これは「履歴」ですから,過去の記録です.後から追加はありますが,変更される内容ではありません.従って,キャッシュが効果的に機能します.memcacheやredisなどのKVSを利用し,オブジェクトをキャッシュする仕組みをご提案しました.キャッシュ機能は機能的には単純です.後から機能を追加することは比較的容易です.効果は非常に高いです.

■目標達成.更にもっと.

ご提案した内容を対策後,後日,本番環境で効果測定を行いました.2つの課題箇所の両方とも目標を達成していました.お客様も喜んでいました.喜んでいるのも束の間,応答時間が速くなることを知ってしまったため欲が出たのでしょう.「更にもっと速くしたいのですが,どうすればよいでしょうか?」と相談を受けました.文章が長くなってしまったので,今回はここまでとします.次回は高負荷,高性能を実現するためのサーバ側の対策案についていくつかご紹介していきたいと思います.

性能診断分析サービス事例 その2

シーマークすずきです.

久々にタイ古式マッサージをしてもらってきました.肩コリがとっても楽になりました.

さて,今回は性能診断分析サービス事例の第二段です.

■CPU稼働率が100%に暴走

お客様は大手のコンシューマ向けWebサイトを運営しています.複数のWebサイトを実施している中,2週間後にそのうちの1つをリニューアルしたことを大々的に告知するテレビコマーシャル(以下TVCM)が開始される予定でした.実はWebアプリケーションのリニューアル開発は既に完了し,本番稼働できる状態でしたが困った問題を抱えていました.それは,ステージング環境では発生しないのに,本番環境では稼動中に突然CPU稼働率が100%に張り付く,というものでした.

Tomcatを起動し,公開用のロードバランサーに参加し実際のリクエストを当て始めると数分で暴走することもあれば,数時間サービスした後に暴走を開始するケースもあった.数日間サービスを順調にしていたと思ったら,暴走してしまう,ということも.一度暴走するとTomcatプロセスを強制停止しなければならず,正常サービスを維持できなくなってしまうのです.

 

■問題事象の定義

TVCMが始まると非常にたくさんのアクセスが来ることが予想されていますが今の状況だと,せっかくリニューアルサイトに集客できてたとしても,サービスを提供できない可能性があるわけです.これは広告効果の問題以前に,会社の信用にかかわります.現状CPU暴走がなぜ発生するのか原因が分からないため,マシン台数をいくら足しても無駄な投資となってしまうため,どうしても早急に根本原因を突き止めたいという状況です.お客様からの我々への依頼内容は,TVCM開始までに対策を講じたいので,できるだけ早期に原因を突き止めてほしい,という内容でした.

今回の問題事象は,

CPU稼働率100%に張り付きっぱなしになる.

ということ.

掴みどころがない,非常に問題切り分けが難しい,ヘンな話しですが,個人的に好きなタイプの案件です.私は難しい仕事の依頼が来ると,ワクワクしてしまいます.

■性能診断分析サービス:計測アプローチ

私たちの性能診断分析サービスの基本アプローチは”数値”で計測し,評価することです.まず,問題事象を捕えることにしました.お客様のこれまで実施した感覚だと十中八九,リニューアル版を本番サービス投入すれば3時間以内に問題事象は1回は発生するだろう,との情報がありました.しかし,実際には,本番機は複数台存在しているが事象が何号機で発生するかは不明なのです.複数台同時に発生することもあります.

我々としては,全部のマシンに性能計測を仕込むのは時間も手間もかかるため,2台だけにモニターの網を張ることにしました.まず,問題事象が発生したことを確認するため,CPU稼働率をモニターすることにしました.同時に,アクセスしてきたリクエストのタイミングを記録することにしました.問題事象を引き起こした直前に実際にどんなリクエストが来たのかを限定し,問題事象を再現するための手懸りをえるためです(容疑者を狭めるため).

■尻尾を掴むヒントは詳細な分析

2台に仕掛けた網にかかったのはモニター開始後の約1時間後でした.これで以下が分かってきました.

  • 問題事象が発生すると確かにCPU稼働率が100%になった.
  • 細かく分析すると,実際には,100%に振り切る前に50%で推移している段階を経ていた.
  • 暴走開始後,しばらく経っても問題事象は解消しない.
  • 問題事象発生後,Tomcatプロセスを終了すると問題事象は解消される.
  • 直前のリクエストが100個のURLに限定した.犯人はこの中にいる.

捕獲した100個の容疑者リクエストURLを順番に叩いていけばステージング環境でも発生できるのではないか,と推定しました.それよりも興味深いのは,問題事象に到達する前にCPU稼働率50%でしばらく維持する点でした.グラフで見れば不思議な形状が一目瞭然です.普通,ジグザグした絵を見せるCPU稼働率のグラフが,平らな2段の階段上になっているのです.

マシン構成を調べてみると本番機は全てデュアルコアのマシンでした.性能診断分析チームで検討した結果,コアが1つづつCPU稼働率100%に振り切っている,という説.恐らく,クワッドコアのマシンならば4段の階段上にグラフが見える様になるのではないか,という意味です.何かの原因でTomcatのワーカースレッドが一つづつ無限ループにハマり,コアが1つづつ死んでいく,という説が分析の結果有力となった仮説でした.

■原因箇所の特定のための仕込み

現象からすると我々の仮説は正しそう.それでは原因となるクラスのメソッドを特定するためにはどうすればよいのでしょうか?性能診断分析チームで検討した結果,CPU稼働率が90%以上に張り付く事象を検知したら,スレッドダンプを自動採取する仕掛けを組むことにしました.

この仕掛けが機能すれば,クラスとメソッドレベルで暴走スレッドのスタックを採取できるため,犯人を特定できる,と考えました.そのため,この再現するであろう100個のURLを順番に実行するJmeterのシナリオを作成し,ステージング環境で問題事象再現テストを行ないました.

■再現しないのはなぜ?

Jmeterのシナリオは30秒毎に1発づつじっくり実行していきました.しかし,100個の容疑者URLは全て正常に実行して終了してしまいました.ステージング環境の再現テスト機はCPU稼働率が50%になることさえもなく,正常にJmeterシナリオが完了してしまったのです.どうして問題事象が再現しないでしょうか.性能診断分析チームはもう一度Jmeterシナリオを走らせたが結果は変わりませんでした.

本番環境とステージング環境の違いは何か?答えが1つ見つかりました.それは本番環境は,全ての本番機が共有するNFSサーバ上のディレクトリを見ていたのです.ステージング環境は,ステージング用のディレクトリを見ています.この設定を意図的に本番環境のディレクトリを見る様にして,先程のJmeterシナリオを実行すると,見事に2段階の階段上のグラフが現れました.

■原因はプログラムのバグ

きれいに問題事象をステージング環境で再現できました.併せて,スレッドダンプも採取することに成功しました.原因もハッキリし,お客様と開発ベンダー様同席でご説明したところ,分析チームが指摘した箇所のクラスのメソッドにバグを発見し修正することができました.特定のファイルがあることを期待したコーディングが原因でした.whileループのbraek条件がその特定ファイルを読むことだったのです.しかし,本番環境のNFSサーバ上のディレクトリには,そのファイルがありませんでした.ステージング環境のディレクトリからファイルをコピーしたところ,whileループから正しく抜けることも確認しました.そもそも,ファイルがなかった時の考慮をソース上修正してもらうことで根本原因を除去しました.

■無事TVCM放映

予定通りTVCMも放映されました.お客様も安心してCM放映開始日を迎えることができて,本当に嬉しそうでした.原因は本当に些細なことでした.しかし,その些細な原因がはっきりしないと,とてつもない恐怖に感じたとサービス責任者が笑顔で御礼の言葉を私達に伝えてくれました.