VPSがクラッキングされた？(その1) ログ調査編 ~ログファイルの意味を学ぶ~
はじめに
勉強のため、個人でさくらのVPSサーバーを契約しているのですが、先日さくらVPSからメールがきました。
メールの内容を要約すると、「私のVPSサーバーが他のサーバーに対して、不審アクセスを行っており、クラッキングされている可能性があるので、調査をお願いします。クラッキングと判断された場合はOSの再インストールをお願いします」という内容のものでした。
そして、不審なアクセスをされたサーバー側のログが以下になります。
[自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:35 +0100] "GET /wp-login.php HTTP/1.1" 200 9509 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:38 +0100] "POST /wp-login.php HTTP/1.1" 200 4575 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:41 +0100] "GET /wp-login.php HTTP/1.1" 200 4433 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:43 +0100] "POST /wp-login.php HTTP/1.1" 200 9818 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:45 +0100] "GET /wp-login.php HTTP/1.1" 200 7951 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:47 +0100] "POST /wp-login.php HTTP/1.1" 403 5 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:35 +0100] "GET /wp-login.php HTTP/1.1" 200 9509 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:38 +0100] "POST /wp-login.php HTTP/1.1" 200 4575 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:41 +0100] "GET /wp-login.php HTTP/1.1" 200 4433 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:43 +0100] "POST /wp-login.php HTTP/1.1" 200 9818 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:45 +0100] "GET /wp-login.php HTTP/1.1" 200 7951 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0" [自分の契約しているVPSのIPアドレス] - - [30/Dec/2019:12:30:47 +0100] "POST /wp-login.php HTTP/1.1" 403 5 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0"
私の契約しているVPSが、/wp-login.phpにログインしようとしているようです。「最初はなんのこっちゃ🤔」と、事の重大さを認識していませんでしたが、一晩寝て起きたら「あれ、これヤバいんじゃ・・・」と焦り始めました。
ともかくログを確認しなければと思ったのですが、色々なログファイルがあれど、あまり意味をわかっていなかったので、Debianのログファイル群の意味も調べながら、ログを調査しました。
各ログファイル群の意味と、実際の調査を様子をまとめました。
環境
VPSサーバー : さくらのVPS
Linuxディストリビューション : Debian 9.11
ログにはどんなものがあるのか
まずは、不審なHTTPメソッドが送られた時のログを確認しようと、/var/logを見ました。
すると、以下のようなログファイルがありました。
- alternatives.log
- auth.log
- btmp
- daemon.log
- debug
- dpkg
- faillog
- kern.log
- lastlog
- messages
- nginx
- postgresql
- syslog
- user.log
- wtmp
これをそれぞれ、見ていきたいと思います。
alternatives.log
これは、alternativesシステムのログのようです。 alternativesシステムとは、複数のプログラムがインストールされている時に、同じような機能を持っていると、どっちを呼び出せば良いの？？とプログラム側は迷ってしまいます。そのような問題を解決するために、プログラム同士が一般名を共有し、その一般名によって呼び出されるプログラムを決めるというシステムの事のようです。
具体的に見ていくと、一番新しいログは、以下のような12月25日のものでした。
update-alternatives 2019-12-25 16:52:57: run with --install /usr/bin/compare compare /usr/bin/compare-im6.q16 10000 --slave /usr/share/man/man1/compare.1.gz compare.1.gz /usr/share/man/man1/compare-im6.q16.1.gz update-alternatives 2019-12-25 16:52:57: link group compare updated to point to /usr/bin/compare-im6.q16
copareという名前のファイルをインストールしているらしいです。これは、日時という点で今回の件とは関係なさそうです。
auth.log
認証に関係するログのようです。具体的に見ていきましょう。
12月30日で前後で、気になるログはこれだけでした。
Dec 30 12:14:13 ik1-319-19699 sshd[29171]: Connection closed by 115.160.163.195 port 44882 [preauth]
意味としては、115.160.163.195という誰かが認証で弾かれたようです。
認証で弾かれているので、問題ないように見えるのですが・・・
btmp
sshログインの失敗ログのようです。これはバイナリファイルなので、lastbコマンドを使った際に、参照されて、人間が読める形で出力されるようです。
一番古いのでは以下のようなログがありました。全然身に覚えないので、おそらく攻撃されているというい事だと思います。 ちなみに韓国からのログインでした。
support ssh:notty 61.41.159.29 Fri Jan 3 23:51 - 23:51 (00:00) backuppc ssh:notty 61.41.159.29 Fri Jan 3 23:51 - 23:51 (00:00) nagios ssh:notty 122.51.23.79 Fri Jan 3 22:38 - 22:38 (00:00)
daemon.log
起動されたデーモンのログのようです。 12月30日の12時半前後のログは1件だけでした。これは、自分の作業だと思うので、問題ないと思います。
Dec 30 12:49:00 ik1-319-19699 systemd[1]: Started Session 12368 of user kohei.
debug
デバッグ関係のログだとは思うのですが、参考になる記事を見つけられませんでした💦
また、最新のログが9月頃のものだったので、今回の件には関係ないと思われます。
dpkg
パッケージ管理関連のログのようです。今回は関係ないと思われるので、スルーします。
faillog
ログイン失敗に関するログファイルのようです。これ自体はバイナリファイルで、faillogコマンドで実行した際に、参照され、人間が読める形に出力されます。
btmpファイルと異なる点としては、faillogは、最後にログインに失敗して以降、ログインに成功していないユーザーのみを表示するという点です。
faillogコマンドを試したところ、何も表示されませんでした。
kern.log
カーネルのログが出力されるようです。12月30日は何もなかったようなので、今回の件には関係ないかと思われます。 基本的に、起動に失敗する時に確認するもののようです。
lastlog
ユーザーごとの最終ログインが記録されるファイルのようです。これ自体はバイナリファイルで、lastlogコマンドで、人間が読める形に出力されるようです。
特に不審なアクセスはありませんでした。
messages
色々なログが収納されているところのようです。一応、どんなログが入ることになっているかを調べるために、/etc/rsyslog.confを覗いてみると以下のようになっていました。
*.=info;*.=notice;*.=warn;\
auth,authpriv.none;\
cron,daemon.none;\
mail,news.none -/var/log/messages
nginx
言わずもがなnginxのログです。
postgresql
これも言わずもがな、postgresqlのログです。
syslog
システム全体のログのようです。ここで、12月30日のログを調べようとしたのですが、ローテーション後で破棄されてしまったようです😭
user.log
これが調べても参考記事が見つからなかったのですが、中身を見たところ、最新のログが9月だったので、今回の件とは関係ないと思います🤔
まとめ
ログを調べてみたのですが、不審なアクセスをしているようなログは見当たりませんでした。ただ、12月30日のsyslogが見れれば違ったんでしょうが、ローテーションで破棄されてしまったようなので、しょうがないと思います。
というより、後から教えていただいたのですが、基本的にVPSに入れたとしたら、犯人は、潜入のログは消すようです。 冷静に考えてみると、そりゃあ確かにその通りですよね。証拠を残して立ち去る犯人は中々いないわけで・・・💦
原因不明なのは気持ちが悪いですが、とりあえず、SSHキーを作り直してVPSのOSを再インストールします😭 その手順や様子もブログにまとめていきたいと思います。
