サーバ

強制終了して破損したMetabaseのH2データベースを復旧する

Metabaseはデータベースを多角的・視覚的に確認できるツールです。
自分の会社では売上や在庫の管理、監視に使っています。

今日、GCPでMetabaseを動かしているサーバがクレジットカード情報の設定ミスで落とされてしまいました。
請求情報を正しく設定して再起動したところ、以下のエラーが出て起動出来ません。

12-17 08:43:14 INFO metabase.util :: Loading Metabase...
12-17 08:43:14 INFO metabase.util :: Maximum memory available to JVM: 455.5 MB
12-17 08:43:19 INFO util.encryption :: Saved credentials encryption is DISABLED for this Metabase instance. 🔓 
 For more information, see https://www.metabase.com/docs/latest/operations-guide/start.html#encrypting-your-database-connection-details-at-rest
12-17 08:43:28 INFO metabase.core :: Starting Metabase in STANDALONE mode
12-17 08:43:28 INFO metabase.core :: Launching Embedded Jetty Webserver with config: 
 {:port 10003}

12-17 08:43:28 INFO metabase.core :: Starting Metabase version v0.31.2 (89c37eb release-0.31.2) ...
12-17 08:43:28 INFO metabase.core :: System timezone is 'Asia/Tokyo' ...
12-17 08:43:28 INFO metabase.plugins :: Loading plugins in directory /home/yusuke/metabase/plugins...
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/presto.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/vertica.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/redshift.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/druid.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/bigquery.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/sparksql.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/googleanalytics.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/google.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/snowflake.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/oracle.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/sqlserver.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/sqlite.metabase-driver.jar... 🔌
12-17 08:43:28 INFO metabase.plugins :: Loading plugin /home/yusuke/metabase/plugins/mongo.metabase-driver.jar... 🔌
12-17 08:43:29 INFO driver.sparksql :: Found metabase.driver.FixedHiveDriver.
12-17 08:43:29 INFO driver.sparksql :: Successfully registered metabase.driver.FixedHiveDriver with JDBC.
WARNING: any? already refers to: #'clojure.core/any? in namespace: monger.collection, being replaced by: #'monger.collection/any?
12-17 08:43:30 INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
12-17 08:43:30 INFO metabase.db :: Verifying h2 Database Connection ...
12-17 08:43:35 ERROR metabase.driver :: Failed to connect to database: Timed out after 5000 milliseconds.
12-17 08:43:35 ERROR metabase.core :: Metabase Initialization FAILED
java.lang.AssertionError: Assert failed: Unable to connect to Metabase h2 DB.
(binding [*allow-potentailly-unsafe-connections* true] (require (quote metabase.driver)) ((resolve (quote metabase.driver/can-connect-with-details?)) engine details))
	at metabase.db$verify_db_connection.invokeStatic(db.clj:402)
	at metabase.db$verify_db_connection.invoke(db.clj:395)
	at metabase.db$verify_db_connection.invokeStatic(db.clj:398)
	at metabase.db$verify_db_connection.invoke(db.clj:395)
	at metabase.db$setup_db_BANG_.invokeStatic(db.clj:464)
	at metabase.db$setup_db_BANG_.doInvoke(db.clj:458)
	at clojure.lang.RestFn.invoke(RestFn.java:421)
	at metabase.core$init_BANG_.invokeStatic(core.clj:162)
	at metabase.core$init_BANG_.invoke(core.clj:139)
	at metabase.core$start_normally.invokeStatic(core.clj:246)
	at metabase.core$start_normally.invoke(core.clj:240)
	at metabase.core$_main.invokeStatic(core.clj:266)
	at metabase.core$_main.doInvoke(core.clj:261)
	at clojure.lang.RestFn.invoke(RestFn.java:397)
	at clojure.lang.AFn.applyToHelper(AFn.java:152)
	at clojure.lang.RestFn.applyTo(RestFn.java:132)
	at metabase.core.main(Unknown Source)
12-17 08:43:35 INFO metabase.core :: Metabase Shutting Down ...
12-17 08:43:35 INFO metabase.core :: Metabase Shutdown COMPLETE

H2のデータベースに接続できないとのこと。H2 Consoleを使って確認してみました。

以下のエラーが出ています。

一般エラー: "java.lang.IllegalStateException: Unable to read the page at position 2314661917102765839 [1.4.200/6]"
General error: "java.lang.IllegalStateException: Unable to read the page at position 2314661917102765839 [1.4.200/6]" [50000-200] HY000/50000 (Help)

それらしきQiitaの記事が見つかりました。
h2 databaseをリカバリする

復旧するにあたり、Metabase同梱のH2のバージョンを使った方が良さそう。metabase.jarを展開してみるとH2のクラスファイルがそのままjarファイルに埋め込まれているようなので、以下のようにリカバリツールを実行しました。

% java -cp ./metabase.jar  org.h2.tools.Recover

これで metabase.db.h2.sql というダンプファイルが作成されます。
~/recovered.mv.db というデータベースファイルでリカバーするには以下の通り。Metabaseではデフォルトではユーザ名、パスワードは空なことに注意。

% java -cp ./metabase.jar org.h2.tools.RunScript -url jdbc:h2:~/recovered -user "" -password "" -script metabase.db.h2.sql -driver org.h2.Driver -showResults

あとは念の為metabase.db.mv.dbを待避させて、recovered.mv.dbをmetabase.db.mv.dbに改名すればok。

% mv metabase.db.mv.db metabase.db.mv.db.bak
% mv ~/recovered.mv.db metabase.db.mv.db

元々1GBくらいだったmetabase.db.mv.dbが復旧したら1.2GBくらいに膨らんだのは何か気になりますがグットこらえて気にしない。

metabase.db.trace.dbという10GBくらいのファイルがあったけどこれは不要らしいので削除しておいた。