conoha、サーバーを強制停止させられるの巻

12265 ワード
Conoha Conoha テキストリンク

conoha のサーバーを止められた。
全部じゃないけど、5個あるサーバーのうち1つ。

みんなこうなったことない？

conohaが好きなんです。
やっぱり一番使いやすい。

とりあえず、原因が Redis だとわかった。

今までRedisのログを取っていなかったが、新しく作り直してまたバグったので、ログを見てた。

上の画像とはちゃうけど、バグった時刻を見ると夜中の2時。

/var/log/redis.log

582:M 09 Sep 08:46:38.642 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
582:M 09 Sep 08:46:38.642 # Server initialized
582:M 09 Sep 08:46:38.642 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
582:M 09 Sep 08:46:38.642 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
582:M 09 Sep 08:46:38.644 * DB loaded from disk: 0.002 seconds
582:M 09 Sep 08:46:38.644 * Ready to accept connections
582:M 09 Sep 12:17:17.839 # Failed opening the RDB file .qwxtgjxkvnofxgdkik (in server root dir /etc/cron.d) for saving: Permission denied
582:M 09 Sep 12:17:18.565 # Failed opening the RDB file crontab (in server root dir /etc) for saving: Permission denied
582:M 09 Sep 16:07:41.902 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
582:M 09 Sep 23:16:46.006 # Failed opening the RDB file .ftzqebo (in server root dir /etc/cron.d) for saving: Permission denied
582:M 09 Sep 23:16:46.755 # Failed opening the RDB file crontab (in server root dir /etc) for saving: Permission denied
582:S 10 Sep 02:29:22.232 * Before turning into a slave, using my master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
582:S 10 Sep 02:29:22.232 * SLAVE OF 192.3.70.16:43659 enabled (user request from 'id=3063 addr=192.3.70.16:43642 fd=116 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=slaveof')
582:S 10 Sep 02:29:23.091 * Connecting to MASTER 192.3.70.16:43659
582:S 10 Sep 02:29:23.091 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:23.195 # Error condition on socket for SYNC: Connection refused
582:S 10 Sep 02:29:24.094 * Connecting to MASTER 192.3.70.16:43659
582:S 10 Sep 02:29:24.094 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:24.210 # Error condition on socket for SYNC: Connection refused
582:S 10 Sep 02:29:25.096 * Connecting to MASTER 192.3.70.16:43659
582:S 10 Sep 02:29:25.096 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:25.216 * Non blocking connect for SYNC fired the event.
582:S 10 Sep 02:29:25.336 * Master replied to PING, replication can continue...
582:S 10 Sep 02:29:25.575 * Trying a partial resynchronization (request d50e932756dd3f0d9dcd357331b6c8987215688a:1).
582:S 10 Sep 02:29:25.700 * Full resync from master: ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ:0
582:S 10 Sep 02:29:25.700 * Discarding previously cached master state.
582:S 10 Sep 02:29:25.700 * MASTER <-> SLAVE sync: receiving 3372687 bytes from master
582:S 10 Sep 02:29:26.674 * MASTER <-> SLAVE sync: Flushing old data
582:S 10 Sep 02:29:26.684 * MASTER <-> SLAVE sync: Loading DB in memory
582:S 10 Sep 02:29:26.684 # Wrong signature trying to load DB from file
582:S 10 Sep 02:29:26.684 # Failed trying to load the MASTER synchronization DB from disk
582:S 10 Sep 02:29:27.100 * Connecting to MASTER 192.3.70.16:43659
582:S 10 Sep 02:29:27.100 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:27.209 * Non blocking connect for SYNC fired the event.
582:M 10 Sep 02:29:28.416 # Setting secondary replication ID to d50e932756dd3f0d9dcd357331b6c8987215688a, valid up to offset: 1. New replication ID is d9592c9ec2fa65795a1e317ca790383826480052
582:M 10 Sep 02:29:28.417 * MASTER MODE enabled (user request from 'id=3063 addr=192.3.70.16:43642 fd=116 name= age=6 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=slaveof')
582:S 10 Sep 02:29:28.823 * Before turning into a slave, using my master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
582:S 10 Sep 02:29:28.824 * SLAVE OF 192.3.70.16:25257 enabled (user request from 'id=3065 addr=192.3.70.16:43750 fd=116 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=slaveof')
582:S 10 Sep 02:29:29.107 * Connecting to MASTER 192.3.70.16:25257
582:S 10 Sep 02:29:29.107 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:29.212 # Error condition on socket for SYNC: Connection refused
582:S 10 Sep 02:29:30.109 * Connecting to MASTER 192.3.70.16:25257
582:S 10 Sep 02:29:30.109 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:30.215 # Error condition on socket for SYNC: Connection refused
582:S 10 Sep 02:29:31.110 * Connecting to MASTER 192.3.70.16:25257
582:S 10 Sep 02:29:31.110 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:31.214 * Non blocking connect for SYNC fired the event.
582:S 10 Sep 02:29:31.318 * Master replied to PING, replication can continue...
582:S 10 Sep 02:29:31.526 * Trying a partial resynchronization (request d9592c9ec2fa65795a1e317ca790383826480052:1).
582:S 10 Sep 02:29:31.631 * Full resync from master: ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ:0
582:S 10 Sep 02:29:31.631 * Discarding previously cached master state.
582:S 10 Sep 02:29:31.631 * MASTER <-> SLAVE sync: receiving 42680 bytes from master
582:S 10 Sep 02:29:31.775 * MASTER <-> SLAVE sync: Flushing old data
582:S 10 Sep 02:29:31.775 * MASTER <-> SLAVE sync: Loading DB in memory
582:S 10 Sep 02:29:31.775 # Wrong signature trying to load DB from file
582:S 10 Sep 02:29:31.775 # Failed trying to load the MASTER synchronization DB from disk
582:S 10 Sep 02:29:32.114 * Connecting to MASTER 192.3.70.16:25257
582:S 10 Sep 02:29:32.114 * MASTER <-> SLAVE sync started
582:S 10 Sep 02:29:32.219 * Non blocking connect for SYNC fired the event.
582:S 10 Sep 02:29:33.641 * Module 'system' loaded from /tmp/exp_lin.so
582:M 10 Sep 02:29:33.764 # Setting secondary replication ID to d9592c9ec2fa65795a1e317ca790383826480052, valid up to offset: 1. New replication ID is b06a0c22cc188640050151198efd9b72ac8e1b65
582:M 10 Sep 02:29:33.764 * MASTER MODE enabled (user request from 'id=3065 addr=192.3.70.16:43750 fd=116 name= age=5 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=slaveof')
594:C 10 Sep 02:44:30.112 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
594:C 10 Sep 02:44:30.113 # Redis version=4.0.14, bits=64, commit=00000000, modified=0, pid=594, just started
594:C 10 Sep 02:44:30.113 # Configuration loaded
594:C 10 Sep 02:44:30.113 * supervised by systemd, will signal readiness
594:M 10 Sep 02:44:30.115 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
594:M 10 Sep 02:44:30.115 # Server can't set maximum open files to 10032 because of OS error: Operation not permitted.
594:M 10 Sep 02:44:30.115 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.

え？
だれのIPよ？


192.3.70.16

しかもマスターとかスレーブとか。
意味わからんし。
俺、やり方知らんし。

まず夕方16時のログね。



582:M 09 Sep 16:07:41.902 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
582:M 09 Sep 23:16:46.006 # Failed opening the RDB file .ftzqebo (in server root dir /etc/cron.d) for saving: Permission denied

セ、セキュリティアタック！？
んでCPUが暴走し始めた 夜中の2時ごろ。


582:S 10 Sep 02:29:22.232 * Before turning into a slave, using my master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
582:S 10 Sep 02:29:22.232 * SLAVE OF 192.3.70.16:43659 enabled (user request from 'id=3063 addr=192.3.70.16:43642 fd=116 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=slaveof')
582:S 10 Sep 02:29:23.091 * Connecting to MASTER 192.3.70.16:43659

なんじゃこりゃあぁぁぁぁ！

これで1年いや、2年近くどれだけの時間を無駄にしたか。
サーバー作っては立て直し。
作っては立て直し。

推測だが、

・誰もRedisなんてみねーだろ。Redisには、パスワードいらんわ。
・Firewall？Redisに関してはフルオープンでいいやん。

ということをしていたら、そこから侵入されめちゃくちゃにされてたみたい。

redisから侵入して、sshdをめちゃくちゃにするとか。
https://teratail.com/questions/113252

ということで、

・超強固なパスワード（自分でも覚えられないレベル）を設定
・サーバーをまた、新しく作り直した
・Firewallは Redisを使うサーバーに対してだけ開けるようにした
・クラックされたサーバーは削除した

ということをやった。

たしかに今までのサーバーもRedis使う、使わない関係なしに作動させておいて、フルオープンで使ってたな。。。。

多分これで治るはず。
conohaさんのサーバーのせいにして申し訳ありませんでした。

しかし、定期的にサーバーがバグる。
普段は1.3に行かない程度のロードアベレージがいきなり70とかを超えるのよ。
再起動してもすぐにオーバーヒート。

2018年の1月頃にも同様な事がありサーバーの詳しい外注の人に聞いた。
結局muninを入れて様子を見てくださいねとのこと。

以前のcentos6のサーバーは削除し、
muninを入れてセキュリティは厳重に1からサーバーを作り直した。

今回は 2019年08月15日頃
深夜3時頃にサーバーが1度程停止しており、あれ？
と思い再起動。

なぜか通ってたはずのPHPのパスが通ってなかったり。
超絶不安定。
curl などを入れ直し、そのまま放置。。。

そしたらまた 2019年08月21日頃サーバーが停止している。
また移動させないとやばいのかな・・・と思ってサーバーを立ち上げてたらconohaからメールが届いてた。

このたびお客様にご利用いただいておりますVPSにおきましてSYN Flood Attackと見受けられる外部への攻撃が発生している状況を確認いたしました。

え。嘘だろ？

今は5個位運用しててバグるの、2個3個なのよな。
しかも定期的に今回はお盆でしょ？
連休を通して外国人が攻撃してきてんじゃないの？
DDOS攻撃とか詳しくないけど俺のサーバーがバグってんじゃなくてconohaがバグってんじゃないの？

この現象に合う前にredisサーバーを立て直そうと勉強してたんだけど、そっちもバグってた。

■ バグったサーバー1 centos7 (DBとして利用 2018年1月)

1年程正常に稼働してたMARIADBサーバー

1 障害発生前のsshd設定について

・ssh鍵認証
・ポート変更 4桁に変更
・パスワードログイン禁止
・rootログイン禁止

2 Firewallは？

オンにしてる。

3 ドメインを設定してる？

してない

4 MYSQL入れてる？

入れてる

■ バグったサーバー2 centos7 (勉強のため 2019年08月10日頃作成)

1 障害発生前のsshd設定について

・ssh鍵認証
・ポート変更 無し
・パスワードログイン禁止
・rootログイン禁止

2 Firewallは？

オンにしてる。

3 ドメインを設定してる？

してない

4 MYSQL入れてる？

redisのみ。

同一IPでサーバーを立て直す

ということをしても結局無駄。
だって、IPアドレスは同じだから結局サーバーは攻撃されるわけ。

色々見たけどさ、
どう考えてもconohaが攻撃されてるんじゃないのか。
と思うんですけどね。

だって同じIPでサーバーを立て直しても即同じ現象が起きるわけですわ。

じゃあWAF使う？

金もかかるし。
面倒くさそうなので使いたくない。

~~

そうなるとWAF機能を毎回停止させないといけなくなりますがそれはそれで面倒くさいですよね。今現在ConoHaのコントロールパネルを開いたままにしていますし…

『そんなに面倒くさいならもはやWAF機能を使用しなければ良いじゃない』と思っている方もおられるかも知れませんがこれをしなれけばセキュリティに不安があります。どうしても必要であるWAF機能を使用しなければならないのです。

~~

結局DBサーバーは GCPに移動させました。

conohaの中の人もサーバーを止めるのであれば、サーバーの中身にアクセスして
原因をはっきりさせたほうが良いと思うんだけど。
外から攻撃されてるのユーザーのせいにしてたらまた同じバグ発生しちゃうじゃん。