Confluence(Tomcat)のアクセスログをMackerelで集計する

このエントリーは、Mackerel Advent Calendar 2018の5日目エントリーです。

Mackerelの公式プラグインであるmackerel-plugin-accesslog は、Webサーバーのアクセスログを集計して、可視化するものです。この記事では、Atlassian社のConflenceのアクセスログを、同プラグインを使用して可視化する方法について取り上げます。

なお、特定製品の設定について説明していますが、Confluenceは内部的にはApache Tomcat(以下Tomcat)にアプリケーションを組み込んで動いているので、TomcatのアクセスログをMackerelで集計する時にそのまま応用できると思います。対象バージョンは以下の通りです。

Confluenceのバージョン: 6.12.2
内蔵のTomcatのバージョン: 9.0.12

server.xmlの設定

Tomcatでは、server.xml の<Engine>要素の子要素として <Valve className="org.apache.catalina.valves.AccessLogValve"を設定することで、アクセスログを出力することができます。 pattern属性の設定によりcommonないしcombined形式での出力を行うことができます。

<Valve className="org.apache.catalina.valves.AccessLogValve" 
   directory="logs" prefix="confluence_access_log" suffix=".log" pattern="combined" />

mackerel-agent.confの設定

/etc/mackerel-agent/mackerel-agent.conf には、以下のように設定します。

[plugin.metrics.confluencelog]
command = "mackerel-plugin-accesslog /opt/atlassian/confluence/current/logs/confluence_access_log.log"

LTSV形式での出力

この状態で、Mackerelのほうでアクセスログの集計は出来ているのですが、LTSV方式でログを出力すると、リクエストのレイテンシーの集計が出来ますので、せっかくですので設定してみましょう。

<Valve className="org.apache.catalina.valves.AccessLogValve"
    rotatable="false" directory="logs" prefix="confluence_access_log" suffix=".log" 
    pattern="host:%h&#9;time:%{yyyy-MM-dd HH:mm:ss}t&#9;ident:-&#9;user:%{X-AUSERNAME}o&#9;method:%m&#9;uri:%U%q&#9;protocol:%H&#9;status:%s&#9;size:%B&#9;referer:%{referer}i&#9;ua:%{user-agent}i&#9;reqtime:%T&#9;thread:%I&#9;remoteIp:%{X-Forwarded-For}i" />

org.apache.catalina.valves.AccessLogValveの設定

タブ区切りでログを出力するには、server.xml内でXMLの実体参照	を記述します。わかりづらっ

細かい書式設定は、こちら

https://tomcat.apache.org/tomcat-9.0-doc/config/valve.html#Access_Logging

Tomcat固有の注意点として、日付の指定フォーマットがjava.text.SimpleDateFormat の書式のため、例えば時間の指定はhhではなくHHとなる点があります。

設定中の

remoteIp:%{X-Forwarded-For}i

の箇所で、ログ書式内のリバースプロキシーが送出しているクライアントのIPアドレスを記録するようにしています。Tomcatでは、%{リクエストヘッダー名}i の書式により、アクセスログに、リクエストヘッダーの値を出力することができます。

user:%{X-AUSERNAME}o&#9;

の箇所はログインユーザーの出力の設定を行っている箇所です。Tomcatでは%{レスポンスヘッダー名}o の書式により、レスポンスヘッダーの値を出力することができます。

リモートIPの記録

Webサーバーがリバースプロキシー配下の場合に、アクセスログのhost項目にクライアントのアドレスを出力したい場合は、server.xmlの<Host>要素以下にclassName="org.apache.catalina.valves.RemoteIpValve"属性を持つ<Valve>要素を追記します。その上で、上記のアクセスログの設定にrequestAttributesEnabled="true"属性を追記します。

<Valve className="org.apache.catalina.valves.RemoteIpValve" remoteIpHeader="X-Forwarded-For" />

<Valve className="org.apache.catalina.valves.AccessLogValve" 
    rotatable="false" directory="logs" prefix="confluence_access_log" suffix=".log"
     requestAttributesEnabled="true"
    pattern="host:%h&#9;time:%{yyyy-MM-dd HH:mm:ss}t&#9;ident:-&#9;user:%{X-AUSERNAME}o&#9;method:%m&#9;uri:%U%q&#9;protocol:%H&#9;status:%s&#9;size:%B&#9;referer:%{referer}i&#9;ua:%{user-agent}i&#9;reqtime:%T&#9;thread:%I" />

ログのローテーション

Tomcatのログのローテーションには色々やり方はありますが、ここではOSのログローテーションで行うようにします。server.xml のアクセスログの設定にrotatable="false"を記述した上で、/etc/logrotate.d/tomcatを作成し、以下のように記述します。

/opt/atlassian/confluence/current/logs/confluence_access_log.log {
  missingok
  copytruncate
  daily
  dateext
  rotate 30
  compress
  delaycompress
}

ローテーションの設定を記述したら sudo logrotate -f /etc/logrotate.d/tomcat を一度手動で実行して設定を反映させてます。*1

アクセスログの出力

上記の設定を行うと、以下のようなアクセスログが出力されます。

f:id:setoazusa:20181205123130p:plain

mackerel-plugin-accesslogの出力

さてお待ちかねMackerel側での出力です。

f:id:setoazusa:20181205121709p:plain

f:id:setoazusa:20181205121735p:plain

f:id:setoazusa:20181205121753p:plain

レイテンシーもちゃんと出力されていますね？

GC時のレイテンシーの低下インシデント例

下記のグラフは、Confluence上でレイテンシーの悪化が発生した際のグラフです。mackerel-plugin-jvm のグラフと重ねると、JavaVM(JVM)のGC処理とレイテンシーの悪化の関連がある可能性が高いことがわかるので、このインシデントに対しては、JVMのヒープ設定の見直しを行いました。

f:id:setoazusa:20181205121918p:plain