SOLVED: 0.34 Post Migration Startup Issues

Hey all,
I upgraded to 0.34.0 from 0.33.3 without incident last week, but after rebooting my server yesterday I found Metabase wouldn't start anymore? I use the plain old java file and run it via a startup script to set environment variables for my postgres database:

set MB_DB_TYPE=postgres
set MB_DB_DBNAME=metabase
set MB_DB_PORT=5432
set MB_DB_USER=redacted
set MB_DB_PASS=redacted
set MB_DB_HOST=localhost

The cmd output looks like this:

c:\metabase>java -jar metabase.jar
01-21 09:29:37 e[1mDEBUG plugins.classloadere[0m :: Using NEWLY CREATED classloader as shared context classloader: clojure.lang.DynamicClassLoader@6d868997
01-21 09:29:38 e[1mINFO metabase.utile[0m :: Loading Metabase...
01-21 09:29:38 e[1mINFO metabase.utile[0m :: Maximum memory available to JVM: 1.3 GB
01-21 09:29:43 e[1mINFO util.encryptione[0m :: Saved credentials encryption is DISABLED for this Metabase instance.
For more information, see Redirecting…
01-21 09:29:44 e[1mWARN servicelocator.DefaultPackageScanClassResolvere[0m :: Cannot search jar file '/C:/metabase/metabase.jar' for classes due to an IOException: invalid block type
java.util.zip.ZipException: invalid block type
at java.util.zip.InflaterInputStream.read(Unknown Source)
at java.util.zip.ZipInputStream.read(Unknown Source)
at java.util.jar.JarInputStream.read(Unknown Source)
at java.util.zip.ZipInputStream.closeEntry(Unknown Source)
at java.util.zip.ZipInputStream.getNextEntry(Unknown Source)
at java.util.jar.JarInputStream.getNextEntry(Unknown Source)
at java.util.jar.JarInputStream.getNextJarEntry(Unknown Source)
at liquibase.servicelocator.DefaultPackageScanClassResolver.loadImplementationsInJar(DefaultPackageScanClassResolver.java:433)
at liquibase.servicelocator.DefaultPackageScanClassResolver.findAllClasses(DefaultPackageScanClassResolver.java:231)
at liquibase.servicelocator.DefaultPackageScanClassResolver.find(DefaultPackageScanClassResolver.java:121)
at liquibase.servicelocator.DefaultPackageScanClassResolver.findImplementations(DefaultPackageScanClassResolver.java:89)
at liquibase.servicelocator.ServiceLocator.findClassesImpl(ServiceLocator.java:226)
at liquibase.servicelocator.ServiceLocator.findClasses(ServiceLocator.java:201)
at liquibase.database.DatabaseFactory.(DatabaseFactory.java:28)
at liquibase.database.DatabaseFactory.getInstance(DatabaseFactory.java:46)
at metabase.db$fn__19610.invokeStatic(db.clj:259)
at metabase.db$fn__19610.invoke(db.clj:259)
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(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
01-21 09:29:52 e[1mINFO metabase.coree[0m :: Starting Metabase in STANDALONE mode
01-21 09:29:52 e[1mINFO metabase.servere[0m :: Launching Embedded Jetty Webserver with config:
{:port 3000}

01-21 09:29:52 e[1mINFO metabase.coree[0m :: Starting Metabase version v0.34.0 (1335215 release-0.34.x) ...
01-21 09:29:52 e[1mINFO metabase.coree[0m :: System info:
{"java.runtime.name" "Java(TM) SE Runtime Environment",
"java.runtime.version" "1.8.0_231-b11",
"java.vendor" "Oracle Corporation",
"java.vendor.url" "http://java.oracle.com/",
"java.version" "1.8.0_231",
"java.vm.name" "Java HotSpot(TM) 64-Bit Server VM",
"java.vm.version" "25.231-b11",
"os.name" "Windows Server 2019",
"os.version" "10.0",
"user.language" "en",
"user.timezone" "Europe/London"}

01-21 09:29:52 e[1mINFO metabase.pluginse[0m :: Loading plugins in c:\metabase\plugins...
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Plugin 'Metabase BigQuery Driver' depends on plugin 'Metabase Google Drivers Shared Dependencies'
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase BigQuery Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? false
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Plugins with unsatisfied deps: ["Metabase BigQuery Driver"]
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :druid...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :druid
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :google...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered abstract driver :google
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase BigQuery Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? true
01-21 09:29:53 e[1mDEBUG plugins.initializee[0m :: Dependencies satisfied; these plugins will now be loaded: ["Metabase BigQuery Driver"]
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :bigquery...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered abstract driver :sql
Load driver :sql took 159.1 ms
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :bigquery (parents: [:sql :google])
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Plugin 'Metabase Google Analytics Driver' depends on plugin 'Metabase Google Drivers Shared Dependencies'
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase Google Analytics Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? true
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :googleanalytics...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :googleanalytics (parents: [:google])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :mongo...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :mongo
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase cannot initialize plugin Metabase Oracle Driver due to required dependencies. Metabase requires the Oracle JDBC driver in order to connect to Oracle databases, but we can't ship it as part of Metabase due to licensing restrictions. See Redirecting… for more details.

01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase Oracle Driver dependency {:class oracle.jdbc.OracleDriver} satisfied? false
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Plugins with unsatisfied deps: ["Metabase Oracle Driver"]
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :presto...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :presto (parents: [:sql])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :redshift...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered abstract driver :sql-jdbc (parents: [:sql])
Load driver :sql-jdbc took 9.0 ms
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :postgres (parents: [:sql-jdbc])
Load driver :postgres took 83.1 ms
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :redshift (parents: [:postgres])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :snowflake...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :snowflake (parents: [:sql-jdbc])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :hive-like...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered abstract driver :hive-like (parents: [:sql-jdbc])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :sparksql...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :sparksql (parents: [:hive-like])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :sqlite...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :sqlite (parents: [:sql-jdbc])
01-21 09:29:53 e[1mDEBUG plugins.lazy-loaded-drivere[0m :: Registering lazy loading driver :sqlserver...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :sqlserver (parents: [:sql-jdbc])
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase cannot initialize plugin Metabase Vertica Driver due to required dependencies. Metabase requires the Vertica JDBC driver in order to connect to Vertica databases, but we can't ship it as part of Metabase due to licensing restrictions. See Redirecting… for more details.

01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Metabase Vertica Driver dependency {:class com.vertica.jdbc.Driver} satisfied? false
01-21 09:29:53 e[1mINFO plugins.dependenciese[0m :: Plugins with unsatisfied deps: ["Metabase Vertica Driver" "Metabase Oracle Driver"]
01-21 09:29:53 e[1mINFO metabase.utile[0m :: Reading Metabase namespaces from namespaces.edn
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :h2 (parents: [:sql-jdbc])
Load driver :h2 took 18.9 ms
01-21 09:29:53 e[1mINFO driver.imple[0m :: Registered driver :mysql (parents: [:sql-jdbc])
Load driver :mysql took 18.0 ms
01-21 09:29:53 e[1mINFO metabase.coree[0m :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
01-21 09:29:53 e[1mINFO metabase.dbe[0m :: Verifying postgres Database Connection ...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Initializing driver :sql...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Initializing driver :sql-jdbc...
01-21 09:29:53 e[1mINFO driver.imple[0m :: Initializing driver :postgres...
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Verify Database Connection ...
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Running Database Migrations...
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Setting up Liquibase...
01-21 09:29:54 e[1mWARN database.DatabaseFactorye[0m :: Unknown database: PostgreSQL
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Liquibase is ready.
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Checking if Database has unrun migrations...
01-21 09:29:54 e[1mWARN metabase.utile[0m :: auto-retry metabase.db$run_schema_migrations_BANG_$fn__19687@e8c9bd4: Cannot find ChangeLogHistoryService for unsupported
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Setting up Liquibase...
01-21 09:29:54 e[1mWARN database.DatabaseFactorye[0m :: Unknown database: PostgreSQL
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Liquibase is ready.
01-21 09:29:54 e[1mINFO metabase.dbe[0m :: Checking if Database has unrun migrations...
01-21 09:29:54 e[1mERROR metabase.coree[0m :: Metabase Initialization FAILED
liquibase.exception.UnexpectedLiquibaseException: Cannot find ChangeLogHistoryService for unsupported
at liquibase.changelog.ChangeLogHistoryServiceFactory.getChangeLogService(ChangeLogHistoryServiceFactory.java:73)
at liquibase.Liquibase.checkLiquibaseTables(Liquibase.java:1217)
at liquibase.Liquibase.listLocks(Liquibase.java:1240)
at metabase.db$migration_lock_exists_QMARK_.invokeStatic(db.clj:198)
at metabase.db$migration_lock_exists_QMARK_.invoke(db.clj:195)
at metabase.db$release_lock_if_needed_BANG_.invokeStatic(db.clj:294)
at metabase.db$release_lock_if_needed_BANG_.invoke(db.clj:290)
at metabase.db$migrate_BANG_$fn__19630.invoke(db.clj:356)
at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:799)
at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:769)
at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:834)
at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:769)
at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:782)
at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:769)
at metabase.db$migrate_BANG_.invokeStatic(db.clj:321)
at metabase.db$migrate_BANG_.invoke(db.clj:300)
at metabase.db$run_schema_migrations_BANG_$fn__19687.invoke(db.clj:454)
at metabase.util$do_with_auto_retries.invokeStatic(util.clj:397)
at metabase.util$do_with_auto_retries.invoke(util.clj:389)
at metabase.util$do_with_auto_retries.invokeStatic(util.clj:401)
at metabase.util$do_with_auto_retries.invoke(util.clj:389)
at metabase.db$run_schema_migrations_BANG_.invokeStatic(db.clj:453)
at metabase.db$run_schema_migrations_BANG_.invoke(db.clj:436)
at metabase.db$setup_db_BANG__STAR_$fn__19694.invoke(db.clj:475)
at metabase.util$do_with_us_locale.invokeStatic(util.clj:664)
at metabase.util$do_with_us_locale.invoke(util.clj:650)
at metabase.db$setup_db_BANG__STAR_.invokeStatic(db.clj:473)
at metabase.db$setup_db_BANG__STAR_.invoke(db.clj:469)
at metabase.db$setup_db_from_env_BANG__STAR_.invokeStatic(db.clj:483)
at metabase.db$setup_db_from_env_BANG__STAR_.invoke(db.clj:480)
at metabase.db$fn__19699$fn__19700.invoke(db.clj:490)
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:76)
at metabase.core$init_BANG_.invoke(core.clj:55)
at metabase.core$start_normally.invokeStatic(core.clj:122)
at metabase.core$start_normally.invoke(core.clj:116)
at metabase.core$_main.invokeStatic(core.clj:142)
at metabase.core$_main.doInvoke(core.clj:137)
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)
01-21 09:29:54 e[1mINFO metabase.coree[0m :: Metabase Shutting Down ...
01-21 09:29:54 e[1mINFO metabase.servere[0m :: Shutting Down Embedded Jetty Webserver
01-21 09:29:54 e[1mINFO metabase.coree[0m :: Metabase Shutdown COMPLETE

I don't know if that first block i/o exception is material? Otherwise, I'm seeing two issues; the unknown database, and the Cannot find ChangeLogHistoryService for unsupported message.

This is the part where you tell me to restore my database from a backup, and I admit I don't have a recent one because damn, my previous metabase upgrades have always gone without a hitch so I blame those guys for shipping a solid and stable product :slight_smile:

If anyone can point me in the right direction, would be much appreciated, & thanks for reading.

nmg

Ok, so yesterday after this happened I downloaded and tried running 0.34.1, and this also failed; today I ran 0.34.1 as a fresh instance without my environment variables and it launched a clean & fresh Metabase - so I once again tried it against my usual instance, and it worked.

I’m confused, but I don’t care. I can remain confused as long as my Metabase is working :nerd_face:

…and yes, I’ve backed it up.

nmg