未明にxmlrpc.phpが攻撃されていたので激重になってた件

Posted by kumacchi on 2014年12月15日 , No comment

WS2014-12-15_13_06_42

３時頃、遅くなったので早く寝ようと思ったらブログのサーバーが重い。

なんだろうと思って調べ始めたら寝られなくなってしまった。原因は上のログ。

最初はなんでこんなの重いんだろうと色々調べるところから始まります。

現在の状態は以下のとおりで、load averageが1.48で少し高めの状態です。通常は0.xと1をきった状態です。

# uptime
13:10:37 up 121 days, 16:46, 4 users, load average: 1.48, 1.03, 0.75
#

これが、８だったり10を超える値になってしました。

こういう状態になると、噂にある過負荷の場合、さくらさんのVPSの場合は、ioの制限が掛かるなどと言われているので、実際にそんな感じになります。

なので、相乗効果で激重になって悪循環です。対策した後もしばらくは重い状態が続いていました、寝てしまったので、いつ回復したのかはわかりませんが、いや、制限が回復しているのかはわかりませんが、今のところまともに使えます。

対策に追われたのであまり記録はとっていません。

とりあえず最初にやったとことはtopコマンドでよく動いている処理のチェックwatchというniconico動画の視聴ページのプログラムがやたらとコールされていたのでこれが原因かと最初は疑いました。

ニコニコレーダーのログ

202.180.34.186 – – [15/Dec/2014:05:06:18 +0900] "GET /watch/sm22433734.html HTTP/1.1" 200 20199
202.180.34.186 – – [15/Dec/2014:05:06:30 +0900] "GET /watch/sm22433954.html HTTP/1.1" 200 22765
202.180.34.186 – – [15/Dec/2014:05:06:48 +0900] "GET /watch/sm22439652.html HTTP/1.1" 302 299
202.180.34.186 – – [15/Dec/2014:05:07:01 +0900] "GET /watch/sm22441261.html HTTP/1.1" 200 22431
202.180.34.186 – – [15/Dec/2014:05:07:33 +0900] "GET /watch/sm22449121.html HTTP/1.1" 200 20702
202.180.34.186 – – [15/Dec/2014:05:08:17 +0900] "GET /watch/sm2245052.html HTTP/1.1" 200 20416

上の様に何やらニコニコ動画の視聴ページがやたらとコールされています。

ユーザーエージェントも表示しないと埒が明かないなーと表示するように設定して再度ログを見る。

202.180.34.186 – – [15/Dec/2014:05:19:01 +0900] "GET /watch/sm22491239.html HTTP/1.1" 504 320 "-" "ICC-Crawler/2.0 (Mozilla-compatible; ; http://kc.nict.go.jp/project1/crawl.html)"
202.180.34.186 – – [15/Dec/2014:05:19:00 +0900] "GET /watch/sm22491112.html HTTP/1.1" 504 320 "-" "ICC-Crawler/2.0 (Mozilla-compatible; ; http://kc.nict.go.jp/project1/crawl.html)"
202.180.34.186 – – [15/Dec/2014:05:21:31 +0900] "GET /watch/sm22508502.html HTTP/1.1" 504 320 "-" "ICC-Crawler/2.0 (Mozilla-compatible; ; http://kc.nict.go.jp/project1/crawl.html)"
202.180.34.186 – – [15/Dec/2014:05:21:44 +0900] "GET /watch/sm22512103.html HTTP/1.1" 504 320 "-" "ICC-Crawler/2.0 (Mozilla-compatible; ; http://kc.nict.go.jp/project1/crawl.html)"

なるほど、
クローラー名がICC-Crawler/2.0

IPは202.180.34.186

ドメイン名が、gw.ucri.jgn-x.jp

独立行政法人情報通信研究機構というお偉いところの様です。

しかしまあ、アクセス自体は割とゆるやかなもので、

リクエスト数も現時点で3356回とそんなでもない。視聴ページのcgiも以前は重かったけど、改良を重ね現在はそこまで重いはずもなくこれは原因では無さそう。

しかし、ログを見ての通り過負荷でサービス不能状態で504出てるのに延々とアクセスするのはやめてくれ。

とりあえず、.htaccessでブロック

BOTをまとめてBAN

こういう時は360Spiderやahrefsbotなどもやたらと目に入って、イライラするので、今まで大目にbotたちを以下のサイトを参考にまとめてBAN

スパムクローラー・ボットを排除する – 工房ブログ～イロドリ

それでも、負荷は収まらない。

MTのコメント機能を止める

movable typeをチェックしてみる。久しぶりにサプリメント見聞録を見てみるとスパムが数十件投稿されていた。

しかしまあ、色々対策してあるので数十件で済んでよかった。

でもまあ、めんどくさいしmtは重いしあれなのでもう、コメントcgiを止めた。パーミッション0にした。これでOK。

コピペブログRSS検索を止める

コピペブログrss検索がかなりコールされていて(360Spiderやahrefsbot)などその他googleも含めてbotがアクセスしているらしい。なのでページにアクセス認証を付けた。どうせ使ってる人は居ないだろう。今は負荷を減らすことが先決。

コピペグログrss検索はDBをSQLiteでつくっていたと思うけど、だいぶ前に作ったものなので今思うとindexも振ってないかもしれない。データがたまっていると重いだろう。この際止めてしまってもいいかもしれない。サーバー資源のムダである。

コピペブログrss検索を止めたのは若干効果があったように思う、topコマンドにかなり居座っていたのでやはり重いcgiなのだろう。根本的な過負荷のせいではあるが。

しかし、過負荷自体は収まっていないようだ。

このブログのlogをチェックする

ここで初心に戻って一番アクセスがあるこのブログのログを見ることにする。

そして、最初のログを発見するに至るわけである。

69.30.245.226

アメリカのカンザスシティーにあるサーバのようです。

管理者情報は

American Registry for Internet Numbers

United States

69.0.0.0 – 69.255.255.255

NET69

となっています。

.htaccessで拒否

アドレス範囲でBANしようかとも思ったのですが、とりあえず.htaccessで69.30.245.226をdenyしました。

これで拒否はされているようですが、まだ過負荷な感じがします。

これが、さくらさんの制限による後遺症なのかアタックによるものなのかがわかりません

69.30.245.226 – – [28/Nov/2014:17:24:14 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:14 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:15 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:15 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:16 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:16 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:16 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:18 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:18 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [28/Nov/2014:17:24:18 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435

しかし、ログを再度見ると１秒間に4回ほどアクセスして来ています。しかもxmlrpc.phpにPOSTしてますし。

これはアタックで過負荷になってるなーと重い.htaccessでは生ぬるいとiptablesで焼きました。

現行ログを調べてみると数万件のリクエストがされていました。

これはひどい。

xmlrpc.phpへのアクセスを制限

これ一時期流行った、wordpressのxmlrpc.phpのPingbackを利用したアタックでしょうか？うちも踏み台にされそうになったようです。

過去の騒動の時に既に踏み台にされた形跡があったので、Disable XML-RPC Pingbackを入れてあるので今回は踏み台にはされていないと思いますが、xmlrpc.phpのアクセス元の制限してたはずなのになーと思って.htaccessを見たら制限されていませんでした。なんで？

<Files ~ "(wp-login.php|xmlrpc.php)$">
order deny,allow
deny from all
allow from deny from 221.xxx.xxx.xxx/11
</Files>

とりあえず慌てて上の.htaccessに追加

サバトラ白猫レオ日記のほうにはちゃんと追加されていました。

そもそも踏み台かどうかはわかりませんが、踏み台にならなくてもアタックの標的にはなってしまうようです。xmlrpc.phpなどのアクセス制限は必須ですね。これって、普通の人やばくね？

普通の人はわかりようがないもんね。

今回の攻撃について調べる

先ほど改めて今回の攻撃についてちゃんと調べました。

11月28日の17時24分14秒からアタックが始まっていました。気づくのが遅くなりさくらさんにはご迷惑をお掛けしたかもしれません。

なんか、重い感じはしてたんですよね。

69.30.245.226 – – [14/Dec/2014:03:59:36 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:38 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:39 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:39 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:40 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:41 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:41 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:42 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:43 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:44 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:45 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435
69.30.245.226 – – [14/Dec/2014:03:59:47 +0900] "POST /xmlrpc.php HTTP/1.0" 200 435

そして気づいた時のログ12月14日の03時59分頃。

いまwordpressの管理画面に入ってみたけどなんかもっさりで重い

14:03:15 up 121 days, 17:38, 4 users, load average: 0.50, 0.43, 0.34

load averageは大したことないtopコマンドで見てもCPU使用率も低い

やっぱり何かIOやCPU使用率の制限が掛かるのだろうか？

69.30.245.226 – – [15/Dec/2014:05:47:44 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"
69.30.245.226 – – [15/Dec/2014:05:47:45 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"
69.30.245.226 – – [15/Dec/2014:05:47:46 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"
69.30.245.226 – – [15/Dec/2014:05:47:46 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"
69.30.245.226 – – [15/Dec/2014:05:47:49 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"
69.30.245.226 – – [15/Dec/2014:05:47:50 +0900] "POST /xmlrpc.php HTTP/1.0" 403 279 "-" "Mozilla/4.0 (compatible: MSIE 7.0; Windows NT 6.0)"

そして、最後のログ、iptablesでブロックしているのでここからはログが残っていません。リファラやユーザーエージェントを表示するようにしています。MSIE 7.0っていう時点であまりまともなアクセスじゃないのがわかります。

# grep 69.30.245.226 blog.kumacchi.com-access_log*|wc -l
1109646
#

そして、xmlrpc.phpへのPOSTリクエストの総数はなんと110万回を超えていました！！

これはひどい。

そんなわけで、これを見た人は自分のサーバーもチェックしてみたください。

と言うかやっぱり海外からのアクセスは全部拒否したほうが安全かもね。(googleとbing以外)

うーん悩ましいなー。

まあ、セキュリティ的には狙われやすいところはアクセス制限をかけていくしかないですね。

また、やはり限られた資源でサーバの運営していくには、メリットのないBOTや出所不明のスクレイピングは大目に見たりせずにどんどんBANしたほうが良さそうですね。

追記：vmstatしてみた

# uptime
14:42:59 up 121 days, 18:18, 4 users, load average: 0.26, 0.91, 1.04
# vmstat 1 20
procs ———–memory———- —swap– —–io—- –system– —–cpu—–
r b   swpd   free   buff cache   si   so    bi    bo   in   cs us sy id wa st
0 0 111336 186048 221636 195360    5    3   167    67    1    1 11 2 83 4 0
0 0 111336 185048 221856 195520    0    0   372     0 450 231 3 2 90 6 0
1 0 111336 176740 221968 195656    0    0   248     0 951 327 9 3 76 13 0
1 0 111336 145112 222220 195824    0    0   380    20 1232 179 50 5 32 13 0
0 0 111336 184228 222264 195908    0    0   104   176 659 249 13 2 76 10 0
1 0 111336 184228 222264 195928    0    0     0     0 241 142 5 1 95 0 0
1 0 111328 183976 222316 195952   64    0    84   304 1307 870 34 4 52 11 0
2 0 111328 181112 222684 196356    0    0   504   488 2024 985 80 5 6 9 0
0 0 111328 182656 222712 196460    0    0    16   336 844 485 22 2 75 1 0
0 0 111328 182656 222712 196476    0    0     0     0 154 137 1 0 99 0 0
0 0 111328 182672 222712 196476    0    0     0     0 105   80 0 1 100 0 0
0 0 111328 182688 222712 196476    0    0     0     0 106   67 0 0 100 0 0
0 0 111328 182768 222712 196476    0    0     0     0 149 107 0 0 100 0 0
0 0 111328 182768 222720 196472    0    0     0    92   57   78 0 0 100 0 0
0 0 111328 182768 222720 196476    0    0     0     0   51   59 0 0 100 0 0
0 0 111328 182768 222744 196652    0    0     0 1160 129 166 1 1 99 0 0
0 0 111328 182816 222744 196716    0    0     0     0   58   61 0 0 100 0 0
0 0 111328 182816 222744 196716    0    0     0     0   62   57 0 0 100 0 0
0 0 111328 182816 222744 196716    0    0     0     0   68   72 0 1 100 0 0
0 0 111328 182816 222744 196716    0    0     0     0   54   55 0 0 100 0 0
#