Shibbolethのログ保存の問題
Shibboleth IdPのログは通常、サーバ上のテキストファイルとして記録され続けますが、この形式では次のような問題があります。
- 複数サーバでロードバランスしている場合にログが分散してしまう（Shibbolethのロードバランサ配下での利用に関してはこちら）。
- ログを様々な条件で検索したい場合に不便。
特に、Shibbolethは標準ではログイン履歴的な情報を参照することが困難なため、監査ログ（idp-audit.log）の検索ができると特に便利です。
先行事例の検討
検索していたところ、いくつかの先行事例が見つかりました。例えば次のようなものがあります。
- 山形大学の「【研究ノート】Shibboleth IdPのログをSQLサーバに記録する方法」では、Shibbolethのログをsyslogで送信し、それをrsyslogdでMySQLに投入している。ログは特にパースせず、そのままsyslogメッセージを1カラムに格納している。
- 「Storing Shibboleth IDP Logs in a Database with IP Addresses」では、SLF4JのDBAppenderを用いて、直接ShibbolethからMS-SQLサーバに格納している。SyslogメッセージのパースはDBへのINSERT時のトリガーを用いて実現している。
時間がたっぷりあれば、後者のほうが魅力的ではありますが、安易にやるならば前者のほうが実に簡単そうです。そこで、まずはsyslogベースで実現してみることにしましたが、やはりsyslogメッセージのパースは実現したいと思います。対象は監査ログということにしました。
（もちろん、信頼性やその他の問題から、Shibboleth IdPから直でDBに入れたほうが良いことはわかっているので、今後時間がある時に、そちらも試してみようかと思います）
今回の構成
Syslogのシステムとしては、山形大の利用したrsyslogではなく、syslog-ngを使ってみることにしました。内蔵でcsvのパーサーがあるなどの特徴が、今回の目的には魅力的に見えたためです。Syslog-ngはlibdbiを用いてSQLのサーバに接続することが可能であり、今回はPostgreSQL対応のlibdbi-driversをインストールして、PostgreSQLに対応することにしました。
Shibboleth IdPから監査ログをsyslog送信
注意：この部分に関しては、Shibbbolethのバージョンが2から3に移る時点で変更が入ったようです。現在、この後半のクライアントIPアドレスとセッションIDの記録の部分を、こちらに書きました。前半に関しても今後追記予定です。
Shibboleth IdPから監査ログをsyslogで送信するのは意外に簡単です。単純にlogging.xmlの内容に次のような<appender/>と、
|
1 2 3 4 5 6 |
<appender name="IDP_SYSLOG" class="ch.qos.logback.classic.net.SyslogAppender"> <SyslogHost>送信先IPアドレス</SyslogHost> <Port>514</Port> <Facility>LOCAL5</Facility> <SuffixPattern>%msg%n</SuffixPattern> </appender> |
次のような<appender-ref/>（追加したのは3行目のIDP_SYSLOGへの参照）を追加すれば、指定したIPアドレスの514/udpにlocal5でidp-audit.logの内容が転送されます。
|
1 2 3 4 |
<logger name="Shibboleth-Audit" level="ALL"> <appender-ref ref="IDP_AUDIT"/> <appender-ref ref="IDP_SYSLOG"/> </logger> |
ただ、Shibboleth IdPの標準のidp-audit.logの内容はクライアントのIPアドレスが含まれないという問題点があります（なぜこのような仕様なのか理解に苦しみます）。その場合は、<appender/>内の<suffixPattern/>の内容を次のように書き狩れば、IPアドレスが末尾に追加されます。
|
1 |
<SuffixPattern>%msg%mdc{clientIP}|</SuffixPattern> |
Shibbolethのマニュアルによると、この%mdcで参照できるパラメータには、clientIPの他にidpSessionIdとJSESSIONIDがあるようです。実運用を考えてみると、単純なidp-audit.logの内容だけではなくShibboleth IdPのセッション情報であるidpSessionIdは何かと必要です（同一IdPセッション中で複数のSPにアクセスするのが普通なので、どのSPにどのIdPセッションでアクセスしたかの情報はかなり重要）。また、JSESSIONIDももしかすると何らかのトラブル対処の役に立つかもしれません。
そこで、さらに次のように<suffixPattern/>を設定すれば、idpSessionIdとJSESSIONIDも一緒にsyslogに送信されることになります。ちなみに、設定中のパイプ印の「|」は、idp-audit.logのフィールド区切り文字で、%msg内の文字列フォーマットに合わせたものです。
|
1 |
<SuffixPattern>%msg%mdc{clientIP}|%mdc{idpSessionId}|%mdc{JSESSIONID}|</SuffixPattern> |
もし、ファイルベースのidp-auditログにも同様のデータが必要だと思われる場合は、name = “IDP_AUDIT”となっている<appender/>内の<suffix/>も同様に設定しましょう。ただし、末尾の%n（改行）を忘れないようにしましょう（こちらはSuffixPatternではなくPatternになります）。
|
1 |
<Pattern>%msg%mdc{clientIP}|%mdc{idpSessionId}|%mdc{JSESSIONID}%n</Pattern> |
Syslog-ngによるパースとDB格納
Syslog-ngの設定は、古典的なsyslog.confとは全く異なる形式のファイルで行います。すでにsyslog-ngが動いている環境では、おそらく通常の/var/log系のログもsyslog-ngで取っているでしょう。そうでない場合は、sourceの設定でUNIXドメインソケットを全部無視して、独自のUDPポートでsyslogを受け付けるようにすれば、古典的syslogやrsyslogとの同居も可能かと思われます。
ソースの設定はOSに依存しますが、今回はFreeBSDで構築したので、次のようなpkgからインストールした標準のままのソース設定です。他のOSでもおそらく標準のままで問題ないでしょう。
|
1 2 3 |
source src { unix-dgram("/var/run/log"); unix-dgram("/var/run/logpriv" perm(0600)); udp(); internal(); file("/dev/klog"); }; |
フィルタは、先ほどのShibboleth IdPの設定でfacilityがlocal5で送信されるので、これも標準設定ファイルにあった次のフィルタを利用します。
|
1 |
filter f_local5 { facility(local5); }; |
次は肝心のパースです。Syslog-ngはcsv-parserという機能でCSV的なデータのパースが可能です。Shibbolethのログは「|」記号で区切られたテキストなのでこの機能でパースできます。
|
1 2 3 4 5 6 7 8 9 10 |
parser p_shib { csv-parser( columns("requestBinding", "requestId", "relyingPartyId", "messageProfileId", "assertingPartyId", "responseBinding", "responseId", "principalName", "authNMethod", "releasedAttributeIds", "nameIdentifier", "assertionIds", "clientIp", "idpSessionId", "jSessionId") flags(escape-backslash,strip-whitespace) delimiters("|") ); }; |
そしてパースした結果をDBにSQLで格納します。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 |
destination d_localpg { sql( type(pgsql) host("localhost") username("*********") password ("********") database("********") table("********") columns("ts timestamp with time zone", "host text", "requestbinding text", "requestid text", "relyingpartyid text", "messageprofileid text", "assertingpartyid text", "responsebinding text", "responseid text", "principalname text", "authmethod text", "releasedattributeids text", "nameidentifier text", "assertionids text", "clientip text", "idpsessionid text", "jsessionid text") values("$R_ISODATE", "$HOST", "$requestBinding", "$requestId", "$relyingPartyId", "$messageProfileId", "$assertingPartyId", "$responseBinding", "$responseId", "$(lowercase ${principalName})", "$authNMethod", "$releasedAttributeIds", "$nameIdentifier", "$assertionIds", "$clientIp", "$idpSessionId", "$jSessionId") indexes("ts", "principalname", "clientip", "idpsessionid") null("") ); }; |
ここで注目するべき点はいくつかあります。
まず、最も気をつけるべき点ですが、syslog-ngの本来的なデータベースの利用法は、syslog-ngから日付けなどに合わせたテーブル（テーブル名に日付けなどが入る）を自動的に作成してそこに格納していくことが前提となっているという点です。つまり、手動でCREATE TABLEしたテーブルに格納していくようなやり方をしようと思うとうまくいきません。テーブルの作成を含めてdestinationの定義で行います。
そうすると、問題はテーブルにログ本体以外の情報を追加したい場合です。このような場合はテーブルに余計なカラムを足すか、プライマリキーで紐付けられた別テーブルのデータを用意する必要があります。データの構造としては後者が良いのでしょうが、たとえばプライマリキーのための連番整数を振るようなことはこのdestinationの定義ではできません（何らかのデータを突っ込む機能と同じ場所でテーブルの定義を行うため、カラムを作るとそこに何らかの値を入れなければならない）。
前者の方法であれば、columnsの中にダミーのカラムを作り、valuesでnullなどを突っ込んでおけば可能なのですが、後々JOIN対象のデータとして用いる場合等には、やはりプライマリキーがないと色々と面倒です。
この場合は、まずはsyslog-ngでテーブルを作らせてから、それに以下のようにalter tableしてserial型のカラムを追加する方法などが使えます。ただし、この方法が使えるのはテーブルにおけるカラムの末尾（destinationで定義したカラムの後）に追加する場合のみです（いずれにせよPostgreSQLではカラムの末尾以外に新カラムを追加することはできないので、別にいいのですが）。具体的にはテーブル名をshiblogとすると、
|
1 2 |
ALTER TABLE shiblog ADD id SERIAL NOT NULL; CREATE INDEX shiblog_id_idx ON shiblog (id); |
のようにしてエントリを追加すれば、自動的に連番が振られることになります。テーブルの末尾にプライマリキーが来ることには好みがあるかもしれませんが、それ以外に方法がないので仕方ありません。
また、小技的ですが、values中に$R_ISODATEでログ時刻を定義すれば、PostgreSQLのTIMESTAMP系の型で受けることができます（上の例ではTIMESTAMP WITH TIME ZONEで受けている）。その他のエントリが全部TEXTなのは私がCHARやVARCHARが大嫌いだからです。
参考までですが、定義中に、”$(lowercase ${principalname})”のようになっているところがあります。このようにsyslog-ngでは組み込み関数がいくつかあり、記録するまでに組み込み関数で文字列を変換することが可能です（principalnameは大文字小文字を区別せずにShibbolethからログとして出てくるので、lowercaseに統一することが望ましい）。詳しくはsyslog-ngのマニュアルを参照してください。
最後にこれらをまとめてログ取得・記録のためのエントリを作成します。
|
1 2 3 4 5 6 |
log { source(src); filter(f_local5); parser(p_shib); destination(d_localpg); }; |
これでsrcに来たログでlocal5のものを取り出し、p_shibでCSVパースしてd_localpgでログを格納できます。
注意
Shibbolethからprincipalnameとしてログに出力される値はログインに使用されたuidです。通常の場合はそれでも困らないと思いますが、もしこの辺りの手法を用いてログインIDとユーザのプライマリなユーザIDが異なる場合は、そのままではログの名寄せができません。そのような場合は、先ほどのようにテーブルにダミーのカラムを追加したり、プライマリキーを設定してJOINするなどの方法で、プライマリなユーザIDと各ログエントリの対応を取るシステムが別途必要となるでしょう。