0.33.4 crashing at startup

SetSails · October 17, 2019, 6:55pm

Dear Metabase team,

I just tried to update to the latest .jar version of metabase.

Getting the following error during startup.

After switching back to 0.33.3 it runs without problems again.

Do you have any advice?

Thank you & Best Regards
Fabian

10-17 18:49:56 INFO metabase.driver :: Initializing driver :h2...
10-17 18:50:01 ERROR driver.util :: Database connection error
org.h2.jdbc.JdbcSQLException: General error: "java.lang.NullPointerException" [50000-197]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:357)
	at org.h2.message.DbException.get(DbException.java:168)
	at org.h2.message.DbException.convert(DbException.java:307)
	at org.h2.engine.Database.openDatabase(Database.java:319)
	at org.h2.engine.Database.<init>(Database.java:280)
	at org.h2.engine.Engine.openSession(Engine.java:66)
	at org.h2.engine.Engine.openSession(Engine.java:179)
	at org.h2.engine.Engine.createSessionAndValidate(Engine.java:157)
	at org.h2.engine.Engine.createSession(Engine.java:140)
	at org.h2.engine.Engine.createSession(Engine.java:28)
	at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:351)
	at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:124)
	at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:103)
	at org.h2.Driver.connect(Driver.java:69)
	at java.sql.DriverManager.getConnection(DriverManager.java:664)
	at java.sql.DriverManager.getConnection(DriverManager.java:208)
	at clojure.java.jdbc$get_driver_connection.invokeStatic(jdbc.clj:271)
	at clojure.java.jdbc$get_driver_connection.invoke(jdbc.clj:250)
	at clojure.java.jdbc$get_connection.invokeStatic(jdbc.clj:411)
	at clojure.java.jdbc$get_connection.invoke(jdbc.clj:274)
	at clojure.java.jdbc$db_query_with_resultset_STAR_.invokeStatic(jdbc.clj:1093)
	at clojure.java.jdbc$db_query_with_resultset_STAR_.invoke(jdbc.clj:1075)
	at clojure.java.jdbc$query.invokeStatic(jdbc.clj:1164)
	at clojure.java.jdbc$query.invoke(jdbc.clj:1126)
	at clojure.java.jdbc$query.invokeStatic(jdbc.clj:1142)
	at clojure.java.jdbc$query.invoke(jdbc.clj:1126)
	at metabase.driver.sql_jdbc.connection$can_connect_QMARK_.invokeStatic(connection.clj:159)
	at metabase.driver.sql_jdbc.connection$can_connect_QMARK_.invoke(connection.clj:154)
	at metabase.driver.sql_jdbc$fn__67106.invokeStatic(sql_jdbc.clj:35)
	at metabase.driver.sql_jdbc$fn__67106.invoke(sql_jdbc.clj:34)
	at clojure.lang.MultiFn.invoke(MultiFn.java:234)
	at metabase.driver.util$can_connect_with_details_QMARK_$fn__18956.invoke(util.clj:31)
	at metabase.util$do_with_timeout$fn__14061.invoke(util.clj:334)
	at clojure.core$binding_conveyor_fn$fn__5754.invoke(core.clj:2030)
	at clojure.lang.AFn.call(AFn.java:18)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at org.h2.engine.Database.unlockMeta(Database.java:947)
	at org.h2.engine.Session.commit(Session.java:704)
	at org.h2.store.PageStore.removeOldTempIndexes(PageStore.java:402)
	at org.h2.store.PageStore.openExisting(PageStore.java:374)
	at org.h2.store.PageStore.open(PageStore.java:289)
	at org.h2.engine.Database.getPageStore(Database.java:2552)
	at org.h2.engine.Database.open(Database.java:709)
	at org.h2.engine.Database.openDatabase(Database.java:286)
	... 35 more
10-17 18:50:01 ERROR metabase.core :: Metabase Initialization FAILED
java.lang.Exception: General error: "java.lang.NullPointerException" [50000-197]
	at metabase.driver.util$can_connect_with_details_QMARK_.invokeStatic(util.clj:36)
	at metabase.driver.util$can_connect_with_details_QMARK_.doInvoke(util.clj:19)
	at clojure.lang.RestFn.invoke(RestFn.java:442)
	at clojure.lang.Var.invoke(Var.java:393)
	at metabase.db$fn__17930$verify_db_connection__17939$fn__17942$fn__17943.invoke(db.clj:417)
	at metabase.db$fn__17930$verify_db_connection__17939$fn__17942.invoke(db.clj:415)
	at metabase.db$fn__17930$verify_db_connection__17939.invoke(db.clj:408)
	at metabase.db$fn__17930$verify_db_connection__17939$fn__17940.invoke(db.clj:411)
	at metabase.db$fn__17930$verify_db_connection__17939.invoke(db.clj:408)
	at metabase.db$setup_db_BANG__STAR_$fn__17975.invoke(db.clj:480)
	at metabase.util$do_with_us_locale.invokeStatic(util.clj:677)
	at metabase.util$do_with_us_locale.invoke(util.clj:663)
	at metabase.db$setup_db_BANG__STAR_.invokeStatic(db.clj:479)
	at metabase.db$setup_db_BANG__STAR_.invoke(db.clj:475)
	at metabase.db$setup_db_from_env_BANG__STAR_.invokeStatic(db.clj:489)
	at metabase.db$setup_db_from_env_BANG__STAR_.invoke(db.clj:486)
	at metabase.db$fn__17980$fn__17981.invoke(db.clj:496)
	at clojure.lang.Delay.deref(Delay.java:42)
	at clojure.core$deref.invokeStatic(core.clj:2320)
	at clojure.core$deref.invoke(core.clj:2306)
	at clojure.core$partial$fn__5839.invoke(core.clj:2623)
	at metabase.core$init_BANG_.invokeStatic(core.clj:77)
	at metabase.core$init_BANG_.invoke(core.clj:56)
	at metabase.core$start_normally.invokeStatic(core.clj:123)
	at metabase.core$start_normally.invoke(core.clj:117)
	at metabase.core$_main.invokeStatic(core.clj:143)
	at metabase.core$_main.doInvoke(core.clj:138)
	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)
Caused by: org.h2.jdbc.JdbcSQLException: General error: "java.lang.NullPointerException" [50000-197]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:357)
	at org.h2.message.DbException.get(DbException.java:168)
	at org.h2.message.DbException.convert(DbException.java:307)
	at org.h2.engine.Database.openDatabase(Database.java:319)
	at org.h2.engine.Database.<init>(Database.java:280)
	at org.h2.engine.Engine.openSession(Engine.java:66)
	at org.h2.engine.Engine.openSession(Engine.java:179)
	at org.h2.engine.Engine.createSessionAndValidate(Engine.java:157)
	at org.h2.engine.Engine.createSession(Engine.java:140)
	at org.h2.engine.Engine.createSession(Engine.java:28)
	at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:351)
	at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:124)
	at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:103)
	at org.h2.Driver.connect(Driver.java:69)
	at java.sql.DriverManager.getConnection(DriverManager.java:664)
	at java.sql.DriverManager.getConnection(DriverManager.java:208)
	at clojure.java.jdbc$get_driver_connection.invokeStatic(jdbc.clj:271)
	at clojure.java.jdbc$get_driver_connection.invoke(jdbc.clj:250)
	at clojure.java.jdbc$get_connection.invokeStatic(jdbc.clj:411)
	at clojure.java.jdbc$get_connection.invoke(jdbc.clj:274)
	at clojure.java.jdbc$db_query_with_resultset_STAR_.invokeStatic(jdbc.clj:1093)
	at clojure.java.jdbc$db_query_with_resultset_STAR_.invoke(jdbc.clj:1075)
	at clojure.java.jdbc$query.invokeStatic(jdbc.clj:1164)
	at clojure.java.jdbc$query.invoke(jdbc.clj:1126)
	at clojure.java.jdbc$query.invokeStatic(jdbc.clj:1142)
	at clojure.java.jdbc$query.invoke(jdbc.clj:1126)
	at metabase.driver.sql_jdbc.connection$can_connect_QMARK_.invokeStatic(connection.clj:159)
	at metabase.driver.sql_jdbc.connection$can_connect_QMARK_.invoke(connection.clj:154)
	at metabase.driver.sql_jdbc$fn__67106.invokeStatic(sql_jdbc.clj:35)
	at metabase.driver.sql_jdbc$fn__67106.invoke(sql_jdbc.clj:34)
	at clojure.lang.MultiFn.invoke(MultiFn.java:234)
	at metabase.driver.util$can_connect_with_details_QMARK_$fn__18956.invoke(util.clj:31)
	at metabase.util$do_with_timeout$fn__14061.invoke(util.clj:334)
	at clojure.core$binding_conveyor_fn$fn__5754.invoke(core.clj:2030)
	at clojure.lang.AFn.call(AFn.java:18)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at org.h2.engine.Database.unlockMeta(Database.java:947)
	at org.h2.engine.Session.commit(Session.java:704)
	at org.h2.store.PageStore.removeOldTempIndexes(PageStore.java:402)
	at org.h2.store.PageStore.openExisting(PageStore.java:374)
	at org.h2.store.PageStore.open(PageStore.java:289)
	at org.h2.engine.Database.getPageStore(Database.java:2552)
	at org.h2.engine.Database.open(Database.java:709)
	at org.h2.engine.Database.openDatabase(Database.java:286)
	... 35 more
10-17 18:50:01 INFO metabase.core :: Metabase Shutting Down ...

flamber · October 17, 2019, 7:09pm

Hi @SetSails
From the log, it seems like you’re using H2 for metadata and that file is corrupted.
If you have a backup, then revert to that. If you don’t have a backup, then remember to always make backups in the future before upgrading/downgrading.
Otherwise you need to try to repair the corrupted H2 database:
https://www.metabase.com/docs/latest/troubleshooting-guide/application-database.html
And then you should migrate away from H2:
https://www.metabase.com/docs/latest/operations-guide/migrating-from-h2.html

SetSails · October 17, 2019, 10:10pm

HI @flamber, thank you for the quick reply.

What’s odd though, is that switching back to 0.33.3 immediately solved the issue.

If the H2 database was corrupted - would 0.33.3 not have the same issues ?

Thank you & Best Regards
Fabian

flamber · October 17, 2019, 10:17pm

@SetSails
Yes, if it was corrupted, then shouldn’t work on 0.33.3 either.
The error code it returns (50000-197) is so general that it doesn’t tell much.
You should check the file metabase.db.mv.trace - it should contain more details.
In either case, I would highly recommend that you migrate away from H2.

EDIT: How big is your H2 database?