アプリケーション内部分析によるレスポンス遅延原因の特定

アプリケーション内部分析によるレスポンス遅延原因の特定

2015/12/16掲載

2015年11月12日(木)に弊社ユーザ総会『COMPUS 2015 -性能管理を考える会- 』を開催いたしました。弊社からは「ES/1 NEOシリーズを活用した性能分析事例のご紹介」と題して、お客様からご依頼いただいた評価分析事例を発表させていただきました。今月はその中から、「アプリケ―ション内部分析によるレスポンス遅延原因の特定」をご紹介いたします。

アプリケ―ション内部分析によるレスポンス遅延原因の特定

概要

2015 年2月に、ES/1 NEO APM(Application Performance Management)シリーズを新しくリリースいたしました。今までのES/1 NEOシリーズでは主にシステムリソースを定期的に取得し、そのデータを元に分析を行っていました。ES/1 NEO APMシリーズはエンドユーザが実際に使用している体感レスポンスの計測と、サーバ内の各処理時間を計測することが可能であり、どの処理においてレスポンスが遅くなっているかを把握することができます。

背景

今回評価分析を行ったシステムは、医療カルテを登録/参照するシステムです。レスポンス遅延があったため、運用側では都度リソースの増強を行ってきましたが改善されませんでした。また運用側でテストも実施し、レスポンスが悪そうな箇所は体感的に把握していましたが、その内容を説明しても開発側からの回答はない状況でした。そのためES/1 NEOシリーズを導入し性能分析を実施させていただきました。

環境はWindows 2008 R2サーバ3台で、内訳はAPサーバ2台、DBサーバ1台の環境です。アプリケーションはasp.netで構築されており、RDBにはOracle11gを使用しています。

図1
<図1:対象システム概要図>

リソースから見た稼働状況

まずはリソースの使用状況を確認しました。都度ハード増強していたとのことですが定期的なデータ取得を行っていなかったため、実際にどのように稼働しているかを確認する必要がありました。

プロセッサ、メモリー、I/O、Oracle、HTTPアクセスログの結果をES/1にて分析しました。プロセッサ使用率は負荷をかけても20%未満で推移しており、全く問題のない値で推移していることが判明しました。これ以外の項目についても特にボトルネックになるような値ではなく、リソース的には全く問題がなく稼働できることが証明されました。

図2
<図2:各サーバのプロセッサ使用率>

APMから見た稼働状況

次にES/1 NEO APMからアプリケーションの稼働状況を確認しました。ES/1 NEO APMは大きく2つの情報を取得することが可能です。

1. エンドユーザが処理を依頼してから実際に描画されるまで(End to End)の時間
2. サーバ内の各処理の経過時間

また、これらの2つの処理を結びつけることによりどの要求がどこで遅くなっているかを把握することも可能です。

その結果、特定のURLにおいてレスポンスが非常に悪いことが判明しました。その特定のURLを更に分析したところ、特定のURLが実行される際には必ずあるSQL文が実行されており、あるSQL文の処理時間が非常に悪いことが判りました。図3のように1つのURLを処理するのに約15秒かかりそのうち特定のSQL文は10秒強かかっています。この結果からレスポンス悪化の原因の1つはこのSQL文と断定しました。

図3
<図3:レスポンス悪化の確認>

他にこのURLでは同期処理が多く発生することも判明しました。このURLの処理時間の内、約3割程度は同期処理によるものでした。この同期処理はシステム設計上、必須の可能性もありますが、レスポンを悪化させる原因の一つであると言えます。

図4
<図4:同期処理の発生状況>

結論

今回ES/1 NEOシリーズにて分析を実施したところ以下4点判明しました。
  1. リソースは潤沢に割り当てておりパフォーマンス上の懸念はない
  2. 特定のSQL文がレスポンスの悪化を引き起こしている
  3. レスポンスが悪いURLでは同期処理が発生している
  4. プログラム上IEの互換を強制するDLLが埋め込まれていた
既存のES/1 NEOシリーズでは確認することができなかったアプリケーション内部の分析を、ES/1 NEO APMを用いることにより詳細に分析することが可能になりました。これにより、ES/1 NEOシリーズは今まで以上に多くのユーザ様のお役に立つことができます。

上記内容についてご興味がございましたら、弊社担当営業にお気軽にお問合せください。