Raspberry pi2で立てていた自宅サーバーが壊れました! | no news.

Raspberry pi2で立てていた自宅サーバーが壊れました!

はじめに

事の発端は昨日の夜。そろそろパッケージのアップデートがあるだろうと思って

# apt-get update
# apt-get upgrade

を行いました。php周りのアップデートがあったようです。あとからログを見たらこんな感じでした。※1

Start-Date: 2016-04-29  20:12:57
Commandline: apt-get upgrade
Upgrade: php-pear:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-gd:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-intl:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), libgd-dev:armhf (2.1.0-5, 2.1.0-5+deb8u1), libgd3:armhf (2.1.0-5, 2.1.0-5+deb8u1), libgd2-xpm-dev:armhf (2.1.0-5, 2.1.0-5+deb8u1), php5-fpm:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-readline:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-curl:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-dev:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-mysql:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-common:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-cli:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1), php5-mcrypt:armhf (5.6.19+dfsg-0+deb8u1, 5.6.20+dfsg-0+deb8u1)
Error: Sub-process /usr/bin/dpkg returned an error pre (1)
End-Date: 2016-04-29  20:14:18

upgradeが終わったあとにエラーの文字が。なんだろう?と思いつつ再度upgradeをかけたところ普段のアップグレード時に見慣れない文字列がパラパラと出てきました。

エラーメッセージがターミナルに出るのは非常にまずい状態。さっそくこのWordPressで作ったブログを見るととりあえず表示はできている様子。しかしsshが通らない(connection timeoutになる)ので何が起こっているのかわからない。自宅のだし、死にそうなぐらい眠かった&体中痛かったので、もういいや、と思い寝ました。

今朝起きて調べてみると、あれ、ブログ表示できてなくね?DB接続エラーとか出てね?ということでこりゃまずいと対処することにしました。

※1 upgrade時のログではなく、/var/log/apt/history.logの抜粋です
※2 /var/log/syslog見たらこんなログが大量に残っていました。

Apr 29 06:27:05 raspberrypi rsyslogd0: action 'action 18' resumed (module 'builtin:ompipe') [try http://www.rsyslog.com/e/0 ]

同じような症状の方がいました rsyslogd-2007: action ‘action 18’ suspended が出る場合の対策
  ログに出ている通りhttp://www.rsyslog.com/e/0を参照してみると

Re: Discussion for KB Entry 7218 – Syslogtag rsyslogd-0
by hukrause on Thu Nov 26, 2015 10:22 am

If your server is headless, disable xconsole entry:

# daemon.*;mail.*;\
# news.err;\
# *.=debug;*.=info;\
# *.=notice;*.=warn |/dev/xconsole

best regards,

Hubert

とのことなので、/etc/rsyslogd.confの最後の部分をコメントアウトしてservice rsyslog restart しておきました。x window(X.org)のコンソールだろうし、試しに

daemon.*;mail.*;\
       news.err;\
       *.=debug;*.=info;\
       *.=notice;*.=warn       -/var/log/xconsole

として見たらほぼ/var/log/syslogに出るようなことが残っていました。

エラーメッセージにあるのはompipe: Pipe Output Moduleのようです。確かに元のryslog.confを見ると

 *.=notice;*.=warn |/dev/xconsole

とあるのでここで引っかかったのでしょう。それにしても’action 18’ってなんなんだ。。。あと今回の件と関係なさそう。

何が問題?

syslogの問題はさておき、このサーバーはブログが表示されないと困るのでDBをどうにかすることにしました。そこでmysqlサーバを再起動してみました。エラー。※3

160430 10:03:14 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
160430 10:03:14 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
160430 10:03:14 [Note] /usr/sbin/mysqld (mysqld 5.5.44-0+deb8u1) starting as process 2313 ...
160430 10:03:14 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
160430 10:03:14 [Note] Plugin 'FEDERATED' is disabled.
160430 10:03:14 InnoDB: The InnoDB memory heap is disabled
160430 10:03:14 InnoDB: Mutexes and rw_locks use GCC atomic builtins
160430 10:03:14 InnoDB: Compressed tables use zlib 1.2.8
160430 10:03:14 InnoDB: Using Linux native AIO
160430 10:03:14 InnoDB: Initializing buffer pool, size = 128.0M
160430 10:03:14 InnoDB: Completed initialization of buffer pool
160430 10:03:14 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
160430 10:03:14  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Error: trying to access page number 4294909104 in space 0,
InnoDB: space name ./ibdata1,
InnoDB: which is outside the tablespace bounds.
InnoDB: Byte offset 0, len 16384, i/o type 10.
InnoDB: If you get this error at mysqld startup, please check that
InnoDB: your my.cnf matches the ibdata files that you have in the
InnoDB: MySQL server.
160430 10:03:15  InnoDB: Assertion failure in thread 1995801104 in file fil0fil.c line 4578
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
01:03:15 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 346093 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x30000
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
160430 10:03:15 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

あー。。。innodbでトラブっているらしい。ありえんこともない。というのも今朝になってもsshで繋がらないので強制的に電源引っこ抜いてやりましたから。そら壊れないほうがおかしいですわな。

※3 起動時のログではなく、/var/log/mysql/error.logの抜粋です

対処

うちの環境では/var/はrasperry piのSDカードには載っていなく、USBで接続したスティック型のSSDが刺さっています。これも数年前に買ったシロモノなのでコイツ自体に問題がある可能性も高いので、mysqlサーバ自体を他のサーバに移すことにしました。
問題の他のサーバーですが、以前openstackの検証機として使っていたマシンが、今ではkvmの仮想環境マシンになっています。これにmysql専用の仮想サーバー立てて、raspberry piから見に行かせることにしました。多分こっちのほうがデータは壊れにくいでしょう(なんとなく)。

スポンサーリンク
レクタングル大

仮想mysqlサーバーの構築

というわけで下記コマンドで仮想サーバー立てました。

$ sudo su -
# virt-install --connect qemu:///system -n ubuntu-14.04.mysqlserver -r 4096 -f /var/local/vm/ubuntu/ubuntu-14.04.mysqlserver.qcow2 -s 100 -c /var/local/vm/installer/ubuntu-14.04-server-amd64.iso --graphics vnc,port=6001,listen=0.0.0.0  --os-type linux

とりあえず超焦っていたので細かいオプションはおいといて、vncで繋いでインストールを進めました。とりあえずOpenSSHのみ入れておきました。

仮想mysqlサーバーの設定

とりあえずmysqlサーバ入れて、dbのバックアップが4月18日のしか無かったのでとりあえずそれを戻すことにしました。

# これはraspberry pi側での作業。dumpしておいたDBファイルを仮想mysqlサーバーにコピー。
# scp  mysql.alldatabases.20160418.sql xxx@192.168.89.39:/tmp/
# これはmysqlの仮想サーバーでの作業。mysqlサーバーのインストールとDBのリストアです。
# apt-get update
# apt-get upgrade
# apt-cache search maria
# 一瞬maria dbにしようかと思ったがとりあえず復旧が先と判断してやめた
# apt-get install mysql-server
# mysql -uroot -p
# rootでログインできることを確認
# mysql -u root -p < /tmp/mysql.alldatabases.20160418.sql 

とりあえずDBのデータの復旧まで行きました。あとはraspberry pi側から仮想サーバーのmysqlサーバーを見に行かせれば復帰するはず。

raspberry piから仮想mysqlサーバーにアクセスさせる設定

ああ、それならwordpress_user@123.123.123.123 みたいなの作ってwp-config.php書き換えれば楽勝っしょ。そう考えていた時代が私にもありました。

$ mysql -u root -p
mysql> grant all privileges on wpdb.* to 'wordpress_user'@'123.123.123.123' identified by 'p@ssw0rd';
Query OK, 0 rows affected (0.00 sec)

mysql> Bye
$ 

これでraspberry piから仮想mysqlサーバーにアクセスできるはず。

$ mysql wpdb -u wordpress_user@123.123.123.123 -p 
Enter password: 
ERROR 2003 (HY000): Can't connect to MySQL server on '192.168.89.39' (111)
$

なに。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。

FLUSH PRIVILEGESもやりましたが変わらず。ファイアウォールは?

# ufw status
状態: 非アクティブ
# 

あえてFWを有効にしてみる。

# ufw allow 3306
# ufw allow 22
# ufw enable

アクセスできず。そりゃそうだ。

いろいろ探しまわったところ、

6.2.7 アクセス拒否エラーの原因

に答えがありました。

サーバーがネットワーク接続を無視するように構成されていないこと、または (リモート側から接続しようとする場合に) サーバーのネットワークインタフェース上でローカル側でのみ待機するように構成されていないことを確認します。サーバーが --skip-networking を指定して起動された場合、サーバーは TCP/IP 接続を受け入れません。サーバーが --bind-address=127.0.0.1 を指定して起動された場合、サーバーはローカルのループバックインタフェース上でのみ TCP/IP 接続を待機するためリモート接続を受け入れません。

設定ファイルを確認してみます。

# grep bind-address /etc/mysql/my.cnf 
bind-address           = 127.0.0.1
#

ですよね!というわけでbind-addressを書き換えてやればいいわけですが、、、私勘違いしていました。bind-addressにraspberry piのIP書くんだと思っていましたが、実際はmysqlサーバーのIPを書くのでした。というわけで最終的に

# grep bind-address /etc/mysql/my.cnf 
#bind-address           = 127.0.0.1
bind-address            = 123.234.123.234 mysqlサーバーのIPアドレス
# 

みたいな感じになりました。というわけでmysqlクライアントからはアクセスできることを確認し、あとはwp-config.phpの書き換えのみです。これは

/** MySQL のホスト名 */
#define('DB_HOST', 'localhost');
define('DB_HOST', '123.123.123.123');

と書き換えました。ということでようやく無事に復旧出来ましたとさ。

最後に

今回の件もあって、ちょっとテコ入れしないとまずいかなと思いました。とりあえず/var/を何とかしないと。syslogは別にsyslogサーバ立ててそこにまとめ、/var/cacheはメモリ上でもいいかなと。あとついでなんでmysqlサーバーもレプリケーションサーバー立てて、さらにちゃんとバックアップ取るようにします。。。あと自宅内だからあまり気にしないけど、wordpress⇔ysql間・レプリケーションサーバとの暗号化も検討しましょう。

ということで本日はここまで。

あ、あと監視!!

スポンサーリンク
レクタングル大

シェアする

  • このエントリーをはてなブックマークに追加

フォローする

スポンサーリンク
レクタングル大