2024.12.03
セキュリティ製品を入れても検出されず…被害事例から見る最新の攻撃トレンド 不正侵入・悪用を回避するポイント
リンクをコピー
記事をブックマーク
山口正徳氏:山口と言います。よろしくお願いします。今日はみなさんお集まりいただきありがとうございます。なんと現時点で参加いただいているのが303人。こんなに多くの方に参加してもらえるとは思ってもいなかったので、変な緊張感に包まれています。カミカミなところとかがあったりしても、そこはあたたかい目で見てもらえればなと思います。
また、ログ分析勉強会のオンライン配信は JAWS-UG 札幌の三浦一樹さんに協力いただています。配信環境の設営、配信レイアウトの作成などをすべてボランティアで対応いただきました。ありがとうございます。
私からは『Webサービスのパフォーマンスとログ分析(入門編)』というところで。Webサービスのパフォーマンスを改善するのに、どういうログをどう分析していけばいいのかについて、少し入り口のところをお話しできればなと思っています。
山口って誰やねんっていう人もいると思いますので、少し自己紹介します。Twitterは@kinunoriというIDでやってます。普段はAWS関連の仕事をやっています。その仕事もあってか、AWSの認定資格をいくつかと、あとPMPだったり認定スクラムマスターなのでプロジェクト管理などもやってます。
セキュリティも昔、少しかじっていたことがあって、CISSPをもっています。もっと昔はログ分析ツールの製品担当とかをやっていました。それが4年前くらいですかね。現在はAWS上で構成されたWebサービスの開発とか構築を行っています。
本日は、Webサービスのパフォーマンスチューニングのために必要と考えるログとその分析方法について少しお話します。ここでは、先ほど釜山さんがお話してくれた中の一部である /var/log/messagesとか、そういったテキストに起こされるものだけではなくてデバッグツールの情報や、継続するコマンドの実行結果等も含めてシステムの状態を可視化するための情報をトータルでログと表現しています。
Webサービスのパフォーマンスチューニングをどうすればいいのかというところとかは今回は話さないです。
このテーマ設定をしたときにちょっと後悔したところもあって、パフォーマンス―チューニングをした結果、またそれを測って、それをどうやって分析するのかまでやらないと中身なくなっちゃうんじゃないのかなというところはあったんですけども。20分じゃ話しきれなくなってしまうので、それはまた次の機会に残しておきたいなと思います。
Webサービスのパフォーマンスチューニングといえば。知る人は知っていると思いますが、ISUCONですね。ISUCONは私、7回から9回まで参加をしていまして。最高で予選1日目の8位で、最後はフェイルで予選落ちするというところが最高結果になっています。
日々の業務とかISUCONで実践した内容とかをまとめて、Webサービスのパフォーマンスチューニングを行うために必要と考えるログとその分析方法として今回お話させていただきます。
注意事項ですが、この資料、今日お話する内容なんですけれども、闇雲に実行すると環境の負荷を上げる原因になる可能性があります。本番環境でいきなりポーンと実行すると怒られるので、まずテスト環境で確認することを推奨します。
いきなりMySQLでスロークエリで0で設定して全部のクエリログを取ろうとすると、ディスクの負荷とかもかかってそもそもパフォーマンスが出なくなるので、本番環境ではやめてください。
パフォーマンスチューニングの定義なんですけども、ここで私が定義しているものとしては一定の条件を満たしたうえで処理できるHTTPのリクエスト数を多くする。HTTPSのリクエスト数を多くするというかたちです。あと一定の条件を満たしたうえでHTTPレスポンスを返す速度を速くする。この2つを満たすものをパフォーマンスチューニングの定義としています。
一定の条件って何って言うと、画像の最適化とかサイズを縮小するというところが認められない、HTML、CSSとかも書き換えられないという環境とか。レスポンスはリクエストが来てから何秒以内に返してください、何ミリセック以内に返してくださいとかっていうような内容をここで一定の条件としています。
これは参考というか有名な言葉ですけれども。「推測するな、計測せよ」と。パフォーマンスチューニングとかもそうなんですね。チューニングするとき、いきなり推測でものごとを実行したとしてもうまくいかないです。
ちゃんと最初に計測をして、そのうえでボトルネックはどこなのかというのをはっきりする。ボトルネックはどこなのかというところを特定したうえでスピードハックをしていきましょう。そのうえでさらに計測するというかたちですね。
なので、計測せずにいきなり推測をしてコードを書き換えるとか、アプリケーションのチューニングを行うというのは、それはあまりよくないアンチパターンです。ちゃんと計測しましょう。
計測を行ったうえでのパフォーマンスチューニングなんですけども。まず通常の業務上のリクエスト状況とかでもいいです。もしくはなにかしらのベンチマーカーを使って計測を行うとかでもいいです。なにかしら今の指標というものがあるはずなので、そのうえで計測を行いましょう。
リクエストをいくつかシミュレーションをして行うとか。Apache Benchを使うとかでもありだと思いますね。その上でパフォーマンスが出ない原因を特定する。特定したうえで改善を適応して、さらに計測をして改善効果があるかどうかを確認する。これを繰り返していくことが、パフォーマンスチューニングだと思っています。
そのうえで今日話す内容は、パフォーマンスが出ない原因を特定するため、そのためにどういうログをどう分析していこうかという話になります。
対象とする構成のイメージは、俗に言うWebの三層構成ですね。クライアントがあって、そこからWebサーバーがあって、裏にアプリケーションサーバーがあって、DBがいると。
WebサーバーはApacheだったりNginxだったりh2oだったり。アプリケーションはNodeだったりとかJava、Perl、Rubyとかいろいろあると思います。DBはMySQL、ポスグレ、SQL Serverとかもあると思います。もしくはキャッシュとかNoSQLとかもあると思います。
あとはクラウドだとマネージドサービスだったりとか。サーバーを立てて構成するものとかもいろいろあると思いますが。そこらへんはあまり深く考えずに、汎用的なかたちで見ていきましょう。
まず1つ目なんですけども、クライアントから見たログを確認するというところです。ログといってもクライアントなので、どうやって見るかと言うと、有名なのはChromeのDevToolですよね。
ここでサイトにアクセスして、これはヤフーさんのサイトなので完全に爆速というか最適化されているような構成を取ってるので、あんまり意味はないですけれども。
左側にあるHTTPステータスと赤く囲っているところと、右側にあるリクエストにかかった時間ですね。ここでどこにどれだけのボトルネックがあるかを見ていきます。
この画面はあまり深掘りしないですけれども、左側のいずれかをクリックすると、そこで実際にどういうタイミングで、どれくらいトータルで時間がかかったかというようなタイムの列に対して、もう少し深掘りした情報も見ることができます。
例えばでかい画像をここで表示していると、そこだけで2、3秒かかったりとかする。そうなるとその画像を最適化、縮小して配信の速度を上げるとか。あとはクライアント側のキャッシュを使って、なるべくサーバーに毎回リクエストが飛んでこないようにする方法もあると思います。
これが、クライアントから見たときにWebサービスがどう見えるかという、1つの指標になるかなというところです。
続いてWebとアプリケーションのログを確認するところですね。WebというのはWebとアプリケーションの2つをミックスしています。まずWebサーバのログですけれども。よく使うものとしてApacheとNginxがあると思います。
上がApacheの2.2系のアクセスログと、下がNginxの1.16系のアクセスログですね。だいたいAWS上でEC2でインストールすると、こういうバージョンのものが入ります、というのを並べています。
左側にどのIPアドレスから接続があったとか、どのコンテンツに対してリクエストがあって、リクエストのメソッドは何が使われていてとか。ステータスコードは何を返していてとかですね。あとはクライアントのブラウザは何を使っているとかが出てきたりします。
Nginxのほうも同じですね。Nginxは、例えばここに3441という別の指標の数字が入ったりとかしますが、時間がかかるものがあったりします。あとはサイズを表現するものもあったりします。ほかの部分に関してはほぼ同じですかね。若干フォーマットは違うものも、俗に言うcombinedログのフォーマットになっています。
ここからどうパフォーマンスを見るかということなんですけれども、このままだとなかなかわかることは少ないです。どの時間にどうリクエストがあったかくらいしかわからないです。それをどうしていこうかというところが次に書いてありますが。
まずNginxの場合ですけれども。Nginxのログの設定ですね。nginx.confの中のlog_formatというのがありますが、ここに"$request_time"を入れることで、そのリクエストから実際にレスポンスを処理するまでの処理時間が表示されます。
Apacheの場合は、log_formatに%Dだとか%Tを追加すると出ます。%Dの場合はナノセックで出るので、細かい時間まで見ることが可能になります。
これを入れてあげてNginxをリロードをしてあげると、指定したログファイルにこの中身が出てきます。この場合だとhttp_x_forwarded_forの前に入ってくるので、このブラウザのユーザーエージェントの情報と、今-(ハイフン)になっているところ、この間に数字として入ってくるイメージです。
実際にリクエストしたものがこちらです。image.pngのリクエストに対してのログですけれども。約0.14秒かかっていますね。
これで、どのリクエストに対してどれくらい時間がかかっているかがわかります。なので、これですべてのリクエストに対してログを取っていくと、それぞれどのparseに対してリクエストがあったらどれだけの時間がかかるとか、すなわちどこにボトルネックがあるのかがわかります。
ただこの状態だとけっこう苦労することが多くて。実際に使ってみるとわかるというか、苦労している人も多いと思うんですけれども、"$request_time"を追加するだけだと分析するのにparseがけっこう必要だったりします。
これ好きなところに入れられるんですよね。今このケースだとx_forwarded_forとユーザーエージェントの間に入れてますが、エンジニアによっては、ほかのところに入れたりということもあります。
parseを書くときは、基本的に正規表現で書かなければいけないのですが、違うところに入っていると正規表現が壊れるので、それをまた直してあげなきゃいけなかったりします。なので、複数の人たちで調査するときには困ることがあります。
あとは開発が必要で追加のフィールドを追加したときにも、同じように正規表現の影響を受けます。調査のための課題が残ります。もちろん独自にカスタマイズせずにこのままで取りますとなれば、fluentdとかで手間をかけずにparseすることも可能です。
この課題にどう対応していくかというところで、LTSVを使います。Labeled Tab separated Valuesというもので、はてなさんで使われているログフォーマットです。けっこう前ですね、2013年くらいに話題になったもので。
当時はてなのCTOだった田中さんが書いたブログで、そこからこれけっこういいんじゃないかってWeb界隈でみんな使い出して。今ではパフォーマンスチューニングするときとか、普段の分析でもLTSVを使うことがあります。
LTSV化したログは下です。このままだとけっこう可読性が先ほどのcombinedログと比べて見づらかったりとかするんですが。ラベルが付いていて、タブ区切りで、かつコロンでセパレートされているので、すごくParseしやすいです。
行指向で作られているので、なにかしら列を追加をしたとしても、それをparseするための正規表現が壊れたりとかしないです。なので非常に扱いやすいことが特徴になっています。扱いやすい、イコール分析や統計を取りやすいということです。
LTSVにしたときに、リクエストタイムとか出てきたりしますけれども、私はこういったものを使ってラベルを付けて分析しています。
Nginxを設定するにはどうすればいいかと言うと、こういったかたちでlog_format ltsvとして入れてあげる。これでリロードしてあげるとLTSV形式で追記されます。
ちょっと書いてないですけど、combinedログ入れてる状態で途中でLTSVすると、同じファイルに違うフォーマットで書かれて死ぬので。一旦アクセスログは古いものは退避して、新しいもので書き換えてあげたほうがいいかなと思います。
LTSVを使いました。そのあと統計情報取りましょうというときに出てくるのが、alpというツールですね。kataribeというツールもありしますが、私はalpを使います。
alpはAccess Log Parserというもので、GitHubで公開されているOSSになります。GOで動くOSSです。こちらを使って統計を取ることで、アクセスログからどのリクエストに対してどれくらい時間がかかっているのかというのを見ることができます。
この場合だと、例えばcssだったりjsがminifyされているので、あんまり処理時間的はかかってないよねと。これを例えばNginxでキャッシュして配信したとしてもあんまり効果は見込めないでしょう。
それよりもこのpngファイルとか、あとchannelっていうところの下のリクエスト、これに時間がかかっているので、ここを改善することでパフォーマンス向上につなげることができるんじゃないかと見ることができます。
これで例えばパフォーマンス改善したあと、もう1回同じように取ると、ここのMAXの数字とかSUMの数字が下がっていれば、その分リクエストに対する処理時間が短くなっていることがわかります。
基本はレスポンス処理に時間がかかっているリクエスト×リクエスト数で対象を決めます。時間とカウントの数で、どれくらいトータルかかっているかというところが出てくるので、そこでどこを改善するかの対象を決めるのがよろしいかなと思います。
関連タグ:
2024.11.29
「明日までにお願いできますか?」ちょっとカチンとくる一言 頭がいい人に見える上品な言い方に変えるコツ
2024.11.27
何もせず月収1,000万円超…オンラインゲームにハマって起こした事業 大学中退し4社立ち上げ・2社売却した起業家人生
2024.11.25
仕事はできるのに、なぜか尊敬されない人が使いがちな言葉5選 老害化を防ぐために大切な心構えとは
2024.12.03
職場の同僚にイライラ…ストレスを最小限に抑える秘訣 「いい人でいなきゃ」と自分を追い込むタイプへの処方箋
2024.11.26
タスクの伝え方が部下のモチベーションを左右する マッキンゼー流、メンバーが動き出す仕事の振り方
2024.11.29
やたらと多い自慢話、批判や噂好き…「自己重要感」が低い社員の特徴 管理職が知っておきたい「一生働きたい職場」の作り方
2024.12.04
いつも遅刻や自慢話…自分勝手な人にイラっとした時の切り返し 不平等な関係を打開する「相手の期待」を裏切る技
2024.11.28
管理職の「疲弊感」がメンバーに伝わるリスク 部下の「働きがい」を育む6つのポイント
2024.12.02
給料や人間関係が良いだけでは部下は満足しない メンバーの「働きがい」を育む5つのステップ
2023.03.21
民間宇宙開発で高まる「飛行機とロケットの衝突」の危機...どうやって回避する?