Recently, I've encountered recurring failures during the initialization of Metabase, leading to multiple shutdowns. Initially, the Metabase dashboard takes around 15 minutes to open due to these initialization failures. However, once the initialization is successful, the dashboard operates smoothly.
However, the main concern is why Metabase initialization failed initially on the NVIDIA CUDA Container Environment.
It's working fine with the same version in the Intel Vaapi environment.
Metabase Dashboard will take almost 15 minutes to open because Metabase Initiation failed initially multiple times:
It stuck on the below screenshot until Metabase Initiation was not successful.
Actually, we run metadata in a Docker containerized environment.
Here are the complete environment details.
root@32c4e4be2463:~# cat /etc/os-release
PRETTY_NAME="Ubuntu 22.04.4 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.4 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy
root@32c4e4be2463:~#
root@32c4e4be2463:~# uname -a
Linux 32c4e4be2463 6.5.0-0.deb12.4-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.5.10-1~bpo12+1 (2023-11-23) x86_64
x86_64 x86_64 GNU/Linux
root@32c4e4be2463:~# nvidia-smi
Thu Apr 11 22:15:20 2024
+---------------------------------------------------------------------------------------+
| NVIDIA-SMI 535.154.05 Driver Version: 535.154.05 CUDA Version: 12.2 |
|-----------------------------------------+----------------------+----------------------+
| GPU Name Persistence-M | Bus-Id Disp.A | Volatile Uncorr. ECC |
| Fan Temp Perf Pwr:Usage/Cap | Memory-Usage | GPU-Util Compute M. |
| | | MIG M. |
|=========================================+======================+======================|
| 0 NVIDIA GeForce RTX 3060 Off | 00000000:01:00.0 Off | N/A |
| 32% 58C P2 47W / 170W | 285MiB / 12288MiB | 3% Default |
| | | N/A |
+-----------------------------------------+----------------------+----------------------+
| 1 NVIDIA GeForce RTX 3060 Off | 00000000:02:00.0 Off | N/A |
| 0% 44C P8 17W / 170W | 17MiB / 12288MiB | 0% Default |
| | | N/A |
+-----------------------------------------+----------------------+----------------------+
+---------------------------------------------------------------------------------------+
| Processes: |
| GPU GI CI PID Type Process name GPU Memory |
| ID ID Usage |
|=======================================================================================|
+---------------------------------------------------------------------------------------+
root@32c4e4be2463:~#
I have found the following errors in the logs. By checking this, it looks like there is an issue with MySQL connectivity initially.
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
ERROR metabase.core :: Metabase Initialization FAILED
2024-04-09T19:35:30.565491+09:00 <info> scorer-metabase-metabase1[1480]: clojure.lang.ExceptionInfo: Unable to connect
to Metabase mysql DB. {}
at metabase.db.setup$fn__33711$verify_db_connection__33716$fn__33717$fn__33718.invoke(setup.clj:102)
Caused by: java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=metabase1-rdb1.ctr)
(port=3306)(type=master) : Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection
refused)
at org.mariadb.jdbc.internal.util.exceptions.ExceptionFactory.createException(ExceptionFactory.java:73)Caused by:
java.sql.SQLNonTransientConnectionException: Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection
refused (Connection refused)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 2nd attempt Starting Metabase in STANDALONE mode and here is the logs
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
INFO db.setup :: Successfully verified MySQL 8.0.36-0ubuntu0.22.04.1 application database connection. ✅
INFO db.setup :: Running Database Migrations...
INFO db.setup :: Setting up Liquibase...
INFO db.setup :: Liquibase is ready.
INFO db.liquibase :: Checking if Database has unrun migrations...
WARN changelog.DatabaseChangeLog :: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
INFO sync.util :: FINISHED: Sync h2 Database 1 'Sample Dataset' (21.8 s)
main ERROR An exception occurred processing Appender metabase-appender java.lang.IllegalArgumentException: No implementation of method: :explain of protocol: #'schema.core/Schema found for class: clojure.lang.Var$Unbound
at clojure.core$_cache_protocol_fn.invokeStatic(core_deftype.clj:583)
at clojure.core$_cache_protocol_fn.invoke(core_deftype.clj:575)
ERROR metabase.core :: Metabase Initialization FAILED
org.apache.logging.log4j.core.appender.AppenderLoggingException: An exception occurred processing Appender metabase-appender at org.apache.logging.log4j.core.appender.DefaultErrorHandler.error(DefaultErrorHandler.java:93)
Caused by: java.lang.IllegalArgumentException: No implementation of method: :explain of protocol: #'schema.core/Schema found for class: clojure.lang.Var$Unbound
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 3rd attempt Starting Metabase in STANDALONE mode and here is the logs
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
ERROR metabase.core :: Metabase Initialization FAILED
clojure.lang.ExceptionInfo: Unable to connect to Metabase mysql DB. {}
at metabase.db.setup$fn__34071$verify_db_connection__34076$fn__34077$fn__34078.invoke(setup.clj:102)
at metabase.db.setup$fn__34071$verify_db_connection__34076$fn__34077.invoke(setup.clj:100)
Caused by: java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=metabase1-rdb1.ctr)(port=3306)(type=master) : Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.sql.SQLNonTransientConnectionException: Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 4th attempt Starting Metabase in STANDALONE mode and here is the logs
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
ERROR metabase.core :: Metabase Initialization FAILED
clojure.lang.ExceptionInfo: Unable to connect to Metabase mysql DB. {}
at metabase.db.setup$fn__34071$verify_db_connection__34076$fn__34077$fn__34078.invoke(setup.clj:102)
Caused by: java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=metabase1-rdb1.ctr)(port=3306)(type=master) : Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.sql.SQLNonTransientConnectionException: Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 5th attempt Starting Metabase in STANDALONE mode and here is the logs
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
INFO db.setup :: Successfully verified MySQL 8.0.36-0ubuntu0.22.04.1 application database connection. ✅
INFO db.setup :: Running Database Migrations...
INFO db.setup :: Setting up Liquibase...
INFO db.setup :: Liquibase is ready.
INFO db.liquibase :: Checking if Database has unrun migrations...
WARN changelog.DatabaseChangeLog :: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
INFO sync.util :: FINISHED: Analyze data for h2 Database 1 'Sample Database' (1.4 s)
INFO task.send-pulses :: Sending scheduled pulses...
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 5th attempts Starting Metabase in STANDALONE mode and here is the logs
INFO metabase.core :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
INFO db.setup :: Verifying mysql Database Connection ...
ERROR metabase.core :: Metabase Initialization FAILED
clojure.lang.ExceptionInfo: Unable to connect to Metabase mysql DB. {}
Caused by: java.sql.SQLException: Connections could not be acquired from the underlying database!
Caused by: com.mchange.v2.resourcepool.CannotAcquireResourceException: A ResourcePool could not acquire a resource from its primary factory or source.
Caused by: java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=metabase1-rdb1.ctr)(port=3306)(type=master) : Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.sql.SQLNonTransientConnectionException: Socket fail to connect to host:metabase1-rdb1.ctr, port:3306. Connection refused (Connection refused)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
INFO metabase.core :: Metabase Shutting Down ...
INFO metabase.server :: Shutting Down Embedded Jetty Webserver
INFO metabase.core :: Metabase Shutdown COMPLETE
In 6th attempts Starting Metabase in STANDALONE mode and here is the logs
4 INFO db.setup :: Successfully verified MySQL 8.0.36-0ubuntu0.22.04.1 application database connection. ✅
INFO db.setup :: Checking if a database downgrade is required...
INFO db.setup :: Running Database Migrations...
INFO db.setup :: Setting up Liquibase...
INFO db.setup :: Liquibase is ready.
INFO db.liquibase :: Checking if Database has unrun migrations...
INFO db.liquibase :: Database has unrun migrations. Checking if migraton lock is taken...
INFO db.liquibase :: No migration lock found.
INFO db.liquibase :: Running 277 migrations ...
INFO impl.StdSchedulerFactory :: Using default implementation for ThreadExecutor
INFO core.SchedulerSignalerImpl :: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
INFO core.QuartzScheduler :: Quartz Scheduler v.2.3.2 created.
INFO jdbcjobstore.JobStoreTX :: Using db table-based data access locking (synchronization).
INFO jdbcjobstore.JobStoreTX :: JobStoreTX initialized.
INFO core.QuartzScheduler :: Scheduler meta-data: Quartz Scheduler (v2.3.2) 'MetabaseScheduler' with instanceId '32c4e4be24631712821773808'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
Using job-store 'org.quartz.impl.jdbcjobstore.JobStoreTX' - which supports persistence. and is clustered.
INFO impl.StdSchedulerFactory :: Quartz scheduler 'MetabaseScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
INFO impl.StdSchedulerFactory :: Quartz scheduler version: 2.3.2
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712821773808 started.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712821773808 shutting down.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712821773808 paused.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712821773808 shutdown complete.
INFO db.custom-migrations :: No forward migration for DowngradeDashboardTab
INFO impl.StdSchedulerFactory :: Using default implementation for ThreadExecutor
INFO core.SchedulerSignalerImpl :: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
INFO core.QuartzScheduler :: Quartz Scheduler v.2.3.2 created.
INFO jdbcjobstore.JobStoreTX :: Using db table-based data access locking (synchronization).
INFO jdbcjobstore.JobStoreTX :: JobStoreTX initialized.
INFO core.QuartzScheduler :: Scheduler meta-data: Quartz Scheduler (v2.3.2) 'MetabaseScheduler' with instanceId '32c4e4be24631712822164665'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
Using job-store 'org.quartz.impl.jdbcjobstore.JobStoreTX' - which supports persistence. and is clustered.
INFO impl.StdSchedulerFactory :: Quartz scheduler 'MetabaseScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
INFO impl.StdSchedulerFactory :: Quartz scheduler version: 2.3.2
INFO jdbcjobstore.JobStoreTX :: ClusterManager: detected 1 failed or restarted instances.
INFO jdbcjobstore.JobStoreTX :: ClusterManager: Scanning for instance "32c4e4be24631712821773808"'s failed in-progress jobs.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712822164665 started.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712822164665 shutting down.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712822164665 paused.
INFO core.QuartzScheduler :: Scheduler MetabaseScheduler_$_32c4e4be24631712822164665 shutdown complete.
UPDATE SUMMARY
Run: 277
Previously run: 0
Filtered out: 5
-------------------------------
Total change sets: 282
INFO db.liquibase :: Migration complete in 11.6 mins
INFO db.setup :: Database Migrations Current ... ✅
INFO metabase.util :: Database setup took 11.8 mins
INFO metabase.core :: Looks like this is a new installation ... preparing setup wizard
INFO metabase.core :: Please use the following URL to setup your Metabase installation:
2024-04-11T16:56:05.792597+09:00 <info> scorer-metabase-metabase1[1399]: http://localhost:3000/setup/
INFO metabase.events :: Loading events namespace: metabase.events.audit-log 👂
INFO sync.util :: FINISHED: step ''sync-dbms-version'' for h2 Database 1 ''Sample Database'' (186.8 ms)
INFO sync.util :: STARTING: step ''sync-timezone'' for h2 Database 1 ''Sample Database''
INFO sync-metadata.sync-timezone :: :h2 database 1 default timezone is "Asia/Tokyo"
INFO sync.util :: FINISHED: step ''sync-timezone'' for h2 Database 1 ''Sample Database'' (191.7 ms)
INFO sync.util :: STARTING: step ''sync-tables'' for h2 Database 1 ''Sample Database''
INFO sync-metadata.tables :: Found new tables: (Table ''PUBLIC.ANALYTIC_EVENTS'' Table ''PUBLIC.FEEDBACK'' Table ''PUBLIC.PEOPLE'' Table ''PUBLIC.REVIEWS'' Table ''PUBLIC.ORDERS'' Table ''PUBLIC.ACCOUNTS'' Table ''PUBLIC.INVOICES'' Table ''PUBLIC.PRODUCTS'')
INFO sync-metadata.tables :: Updating table metadata for Table 8 ''PUBLIC.PRODUCTS''
INFO sync-metadata.tables :: Updating table metadata for Table 3 ''PUBLIC.PEOPLE''
INFO sync-metadata.tables :: Updating table metadata for Table 7 ''PUBLIC.INVOICES''
INFO sync-metadata.tables :: Updating table metadata for Table 5 ''PUBLIC.ORDERS''
INFO sync-metadata.tables :: Updating table metadata for Table 4 ''PUBLIC.REVIEWS''
INFO sync.analyze :: fingerprint-fields Analyzed [*****·············································] 😢 12% Table 2 ''PUBLIC.FEEDBACK''
classify-fields Analyzed [******************································] 😕 36% Table 6 ''PUBLIC.ACCOUNTS''
classify-tables Analyzed [************************************··············] 😋 72% Table 1 ''PUBLIC.ANALYTIC_EVENTS''
INFO sync.analyze :: classify-tables Analyzed [***********************************************···] 😎 96% Table 4 ''PUBLIC.REVIEWS''
INFO sync.util :: FINISHED: step ''classify-tables'' for h2 Database 1 ''Sample Database'' (2.0 s)
2024-04-11T16:56:53.145817+09:00 <info> scorer-metabase-metabase1[1399]: 2024-04-11 16:56:53,144 INFO sync.util :: FINISHED: Analyze data for h2 Database 1 ''Sample Database'' (25.9 s)
2024-04-11T17:12:22.592232+09:00 <info> scorer-metabase-metabase1[1399]: 2024-04-11 17:12:22,591 DEBUG middleware.log :: GET /api/user/current 401 847.3 µs (0 DB calls)
2024-04-11T17:12:22.592315+09:00 <info> scorer-metabase-metabase1[1399]: "Unauthenticated"
2024-04-11T17:12:22.592340+09:00 <info> scorer-metabase-metabase1[1399]:
2024-04-11T17:12:22.602955+09:00 <info> scorer-metabase-metabase1[1399]: 2024-04-11 17:12:22,602 DEBUG middleware.log :: GET /api/session/properties 200 8.3 ms (2 DB calls) App DB connections: 2/7 Jetty threads: 6/50 (1 idle, 0 queued) (53 total active threads) Queries in flight: 0 (0 queued)
After the sixth attempt, Metabase initialized successfully, and the Metabase Dashboard Page opened successfully.
I have added the complete logs please check below: