V.0.40.3.1 Connections could not be acquire from the underlaying database!

Bug reports
1

I've been using Metabase for a few months now without bigger problems. Since upgrading to v.0.40.3.1 we are experiencing exhaustive long loading times which most of the times result in query abortions.

Checking the logs I found multiple of the following reports which don't make much sense to me since nothing has changed regarding the database.

java.sql.SQLException: Connections could not be acquired from the underlying database!
	at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118)
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:692)
	at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
	at metabase.driver.sql_jdbc.execute$fn__80539.invokeStatic(execute.clj:190)
	at metabase.driver.sql_jdbc.execute$fn__80539.invoke(execute.clj:188)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:475)
	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)
	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:472)
	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)
	at metabase.driver.sql_jdbc$fn__82288.invokeStatic(sql_jdbc.clj:54)
	at metabase.driver.sql_jdbc$fn__82288.invoke(sql_jdbc.clj:52)
	at clojure.lang.MultiFn.invoke(MultiFn.java:244)
	at metabase.query_processor.context$executef.invokeStatic(context.clj:59)
	at metabase.query_processor.context$executef.invoke(context.clj:48)
	at metabase.query_processor.context.default$default_runf.invokeStatic(default.clj:68)
	at metabase.query_processor.context.default$default_runf.invoke(default.clj:66)
	at metabase.query_processor.context$runf.invokeStatic(context.clj:45)
	at metabase.query_processor.context$runf.invoke(context.clj:39)
	at metabase.query_processor.reducible$pivot.invokeStatic(reducible.clj:34)
	at metabase.query_processor.reducible$pivot.invoke(reducible.clj:31)
	at metabase.query_processor.middleware.mbql_to_native$mbql__GT_native$fn__47902.invoke(mbql_to_native.clj:25)
	at metabase.query_processor.middleware.check_features$check_features$fn__47016.invoke(check_features.clj:39)
	at metabase.query_processor.middleware.limit$limit$fn__47888.invoke(limit.clj:37)
	at metabase.query_processor.middleware.cache$maybe_return_cached_results$fn__46468.invoke(cache.clj:204)
	at metabase.query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__48148.invoke(optimize_temporal_filters.clj:204)
	at metabase.query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50080.invoke(validate_temporal_bucketing.clj:50)
	at metabase.query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__45587.invoke(auto_parse_filter_values.clj:43)
	at metabase.query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__41716.invoke(wrap_value_literals.clj:161)
	at metabase.query_processor.middleware.annotate$add_column_info$fn__41591.invoke(annotate.clj:608)
	at metabase.query_processor.middleware.permissions$check_query_permissions$fn__46888.invoke(permissions.clj:81)
	at metabase.query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__49009.invoke(pre_alias_aggregations.clj:40)
	at metabase.query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__47089.invoke(cumulative_aggregations.clj:60)
	at metabase.query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__49306.invoke(resolve_joined_fields.clj:102)
	at metabase.query_processor.middleware.resolve_joins$resolve_joins$fn__49619.invoke(resolve_joins.clj:171)
	at metabase.query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__45163.invoke(add_implicit_joins.clj:190)
	at metabase.query_processor.middleware.large_int_id$convert_id_to_string$fn__47852.invoke(large_int_id.clj:59)
	at metabase.query_processor.middleware.format_rows$format_rows$fn__47833.invoke(format_rows.clj:74)
	at metabase.query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__44457.invoke(add_default_temporal_unit.clj:23)
	at metabase.query_processor.middleware.desugar$desugar$fn__47155.invoke(desugar.clj:21)
	at metabase.query_processor.middleware.binning$update_binning_strategy$fn__45974.invoke(binning.clj:229)
	at metabase.query_processor.middleware.resolve_fields$resolve_fields$fn__46691.invoke(resolve_fields.clj:34)
	at metabase.query_processor.middleware.add_dimension_projections$add_remapping$fn__44812.invoke(add_dimension_projections.clj:314)
	at metabase.query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__45041.invoke(add_implicit_clauses.clj:147)
	at metabase.query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__50029.invoke(upgrade_field_literals.clj:40)
	at metabase.query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__45326.invoke(add_source_metadata.clj:123)
	at metabase.query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__49181.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)
	at metabase.query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__45534.invoke(auto_bucket_datetimes.clj:147)
	at metabase.query_processor.middleware.resolve_source_table$resolve_source_tables$fn__46738.invoke(resolve_source_table.clj:45)
	at metabase.query_processor.middleware.parameters$substitute_parameters$fn__48991.invoke(parameters.clj:111)
	at metabase.query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__46790.invoke(resolve_referenced.clj:79)
	at metabase.query_processor.middleware.expand_macros$expand_macros$fn__47539.invoke(expand_macros.clj:184)
	at metabase.query_processor.middleware.add_timezone_info$add_timezone_info$fn__45335.invoke(add_timezone_info.clj:15)
	at metabase.query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__49982.invoke(splice_params_in_response.clj:32)
	at metabase.query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49192$fn__49196.invoke(resolve_database_and_driver.clj:31)
	at metabase.driver$do_with_driver.invokeStatic(driver.clj:60)
	at metabase.driver$do_with_driver.invoke(driver.clj:56)
	at metabase.query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49192.invoke(resolve_database_and_driver.clj:25)
	at metabase.query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__47779.invoke(fetch_source_query.clj:274)
	at metabase.query_processor.middleware.store$initialize_store$fn__49991$fn__49992.invoke(store.clj:11)
	at metabase.query_processor.store$do_with_store.invokeStatic(store.clj:42)
	at metabase.query_processor.store$do_with_store.invoke(store.clj:38)
	at metabase.query_processor.middleware.store$initialize_store$fn__49991.invoke(store.clj:10)
	at metabase.query_processor.middleware.validate$validate_query$fn__50036.invoke(validate.clj:10)
	at metabase.query_processor.middleware.normalize_query$normalize$fn__47915.invoke(normalize_query.clj:22)
	at metabase.query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__45181.invoke(add_rows_truncated.clj:35)
	at metabase.query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49967.invoke(results_metadata.clj:143)
	at metabase.query_processor.reducible$async_qp$qp_STAR___38255$thunk__38256.invoke(reducible.clj:103)
	at metabase.query_processor.reducible$async_qp$qp_STAR___38255.invoke(reducible.clj:109)
	at metabase.query_processor.reducible$sync_qp$qp_STAR___38264$fn__38267.invoke(reducible.clj:135)
	at metabase.query_processor.reducible$sync_qp$qp_STAR___38264.invoke(reducible.clj:134)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$apply.invoke(core.clj:660)
	at metabase.query_processor$process_query.invokeStatic(query_processor.clj:150)
	at metabase.query_processor$process_query.doInvoke(query_processor.clj:144)
	at clojure.lang.RestFn.invoke(RestFn.java:423)
	at clojure.lang.Var.invoke(Var.java:388)
	at metabase.db.metadata_queries$fn__61773$table_rows_sample__61782$fn__61785.invoke(metadata_queries.clj:144)
	at metabase.db.metadata_queries$fn__61773$table_rows_sample__61782.invoke(metadata_queries.clj:131)
	at metabase.sync.analyze.fingerprint$fn__61838$fingerprint_table_BANG___61843$fn__61844.invoke(fingerprint.clj:66)
	at metabase.sync.analyze.fingerprint$fn__61838$fingerprint_table_BANG___61843.invoke(fingerprint.clj:46)
	at metabase.sync.analyze.fingerprint$fn__62014$fingerprint_fields_BANG___62019$fn__62020$fn__62021.invoke(fingerprint.clj:180)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:156)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:149)
	at metabase.sync.analyze.fingerprint$fn__62014$fingerprint_fields_BANG___62019$fn__62020.invoke(fingerprint.clj:178)
	at metabase.sync.analyze.fingerprint$fn__62014$fingerprint_fields_BANG___62019.invoke(fingerprint.clj:174)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058$fn__62061$fn__62062$fn__62063.invoke(fingerprint.clj:204)
	at clojure.lang.PersistentVector.reduce(PersistentVector.java:343)
	at clojure.core$reduce.invokeStatic(core.clj:6827)
	at clojure.core$reduce.invoke(core.clj:6810)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058$fn__62061$fn__62062.invoke(fingerprint.clj:200)
	at metabase.query_processor.store$do_with_store.invokeStatic(store.clj:44)
	at metabase.query_processor.store$do_with_store.invoke(store.clj:38)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058$fn__62061.invoke(fingerprint.clj:197)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058.invoke(fingerprint.clj:186)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058$fn__62059.invoke(fingerprint.clj:191)
	at metabase.sync.analyze.fingerprint$fn__62049$fingerprint_fields_for_db_BANG__STAR___62058.invoke(fingerprint.clj:186)
	at metabase.sync.analyze.fingerprint$fn__62091$fingerprint_fields_for_db_BANG___62096$fn__62097.invoke(fingerprint.clj:218)
	at metabase.sync.analyze.fingerprint$fn__62091$fingerprint_fields_for_db_BANG___62096.invoke(fingerprint.clj:212)
	at metabase.sync.analyze$make_analyze_steps$fn__62248.invoke(analyze.clj:104)
	at clojure.lang.AFn.applyToHelper(AFn.java:154)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$apply.invoke(core.clj:660)
	at metabase.sync.util$fn__40221$run_step_with_metadata__40226$fn__40230$fn__40232.doInvoke(util.clj:360)
	at clojure.lang.RestFn.invoke(RestFn.java:397)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:99)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:93)
	at metabase.sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:116)
	at metabase.sync.util$with_start_and_finish_debug_logging.invoke(util.clj:113)
	at metabase.sync.util$fn__40221$run_step_with_metadata__40226$fn__40230.invoke(util.clj:355)
	at metabase.sync.util$fn__40221$run_step_with_metadata__40226.invoke(util.clj:350)
	at metabase.sync.util$fn__40412$run_sync_operation__40417$fn__40418$fn__40426.invoke(util.clj:451)
	at metabase.sync.util$fn__40412$run_sync_operation__40417$fn__40418.invoke(util.clj:449)
	at metabase.sync.util$fn__40412$run_sync_operation__40417.invoke(util.clj:443)
	at metabase.sync.analyze$fn__62260$analyze_db_BANG___62265$fn__62266$fn__62267.invoke(analyze.clj:121)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:156)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:149)
	at clojure.core$partial$fn__5841.invoke(core.clj:2630)
	at metabase.driver$fn__29808.invokeStatic(driver.clj:527)
	at metabase.driver$fn__29808.invoke(driver.clj:527)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.sync.util$sync_in_context$fn__40133.invoke(util.clj:135)
	at metabase.sync.util$with_db_logging_disabled$fn__40130.invoke(util.clj:126)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:99)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:93)
	at metabase.sync.util$with_start_and_finish_logging$fn__40119.invoke(util.clj:111)
	at metabase.sync.util$with_sync_events$fn__40114.invoke(util.clj:85)
	at metabase.sync.util$with_duplicate_ops_prevented$fn__40105.invoke(util.clj:64)
	at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:177)
	at metabase.sync.util$do_sync_operation.invoke(util.clj:174)
	at metabase.sync.analyze$fn__62260$analyze_db_BANG___62265$fn__62266.invoke(analyze.clj:118)
	at metabase.sync.analyze$fn__62260$analyze_db_BANG___62265.invoke(analyze.clj:113)
	at metabase.task.sync_databases$sync_and_analyze_database_BANG_.invokeStatic(sync_databases.clj:70)
	at metabase.task.sync_databases$sync_and_analyze_database_BANG_.invoke(sync_databases.clj:58)
	at metabase.task.sync_databases.SyncAndAnalyzeDatabase.execute(sync_databases.clj:75)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
Caused by: com.mchange.v2.resourcepool.CannotAcquireResourceException: A ResourcePool could not acquire a resource from its primary factory or source.
	at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1507)
	at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644)
	at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554)
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758)
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685)
	... 138 more
Caused by: org.postgresql.util.PSQLException: The connection attempt failed.
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:315)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:225)
	at org.postgresql.Driver.makeConnection(Driver.java:465)
	at org.postgresql.Driver.connect(Driver.java:264)
	at java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
	at java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)
	at metabase.connection_pool$proxy_data_source$reify__35308.getConnection(connection_pool.clj:29)
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:161)
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:147)
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:202)
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1176)
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1163)
	at com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
	at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1908)
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
Caused by: java.net.SocketTimeoutException: connect timed out
	at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
	at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.base/java.net.Socket.connect(Socket.java:609)
	at org.postgresql.core.PGStream.createSocket(PGStream.java:231)
	at org.postgresql.core.PGStream.<init>(PGStream.java:95)
	at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:98)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:213)
	... 15 more

Diagnosis Info:

{
  "browser-info": {
    "language": "de-DE",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.164 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.10+9-Ubuntu-0ubuntu1.18.04",
    "java.vendor": "Ubuntu",
    "java.vendor.url": "https://ubuntu.com/",
    "java.version": "11.0.10",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.10+9-Ubuntu-0ubuntu1.18.04",
    "os.name": "Linux",
    "os.version": "4.15.0-142-generic",
    "user.language": "en",
    "user.timezone": "Etc/UTC"
  },
  "metabase-info": {
    "databases": [
      "googleanalytics",
      "postgres"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "10.16 (Ubuntu 10.16-0ubuntu0.18.04.1)"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.2.18"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2021-08-26",
      "tag": "v0.40.3.1",
      "branch": "release-x.40.x",
      "hash": "0550b86"
    },
    "settings": {
      "report-timezone": "Europe/Berlin"
    }
  }
}
2

Hi @flo
Which version did you upgrade from?
I cannot easily see from the stacktrace if this is happening the the internal Metabase application database, or if it only a problem with your data warehouse connection.
It looks like network problems between Metabase and the database.

3

Hey @flamber. Thanks for your fast reply!

I upgraded from v0.40.1.

This is what it looks for me as well, but I can pretty confidently exclude problems and connection problems with the external database (data warehouse) as nothing with it has changed as far as I can tell and the database is still working fine with all the other applications. Was there any change on Metabases side? Is there anything I can do to gain further insights in what might cause those issues?

4

Another interesting thing I found in the logs:

[69712935-4fd4-4fe8-8c3d-05e6c1b19118] 2021-08-30T16:25:18+02:00 ERROR metabase.query-processor.middleware.catch-exceptions Fehlerverarbeitungsanfrage: null
{:database_id 2,
 :started_at #t "2021-08-30T14:16:11.157584Z[Etc/UTC]",
 :via
 [{:status :failed,
   :class org.postgresql.util.PSQLException,
   :error "The connection attempt failed.",
   :stacktrace
   ["org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:315)"
    "org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)"
    "org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:225)"
    "org.postgresql.Driver.makeConnection(Driver.java:465)"
    "org.postgresql.Driver.connect(Driver.java:264)"
    "java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)"
    "java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)"
    "--> connection_pool$proxy_data_source$reify__35302.getConnection(connection_pool.clj:29)"],
   :state "08001"}
  {:status :failed,
   :class com.mchange.v2.resourcepool.CannotAcquireResourceException,
   :error "A ResourcePool could not acquire a resource from its primary factory or source.",
   :stacktrace
   ["com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1507)"
    "com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644)"
    "com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554)"
    "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758)"
    "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685)"
    "com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
    "--> driver.sql_jdbc.execute$fn__80542.invokeStatic(execute.clj:190)"
    "driver.sql_jdbc.execute$fn__80542.invoke(execute.clj:188)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:475)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:472)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)"
    "driver.sql_jdbc$fn__82291.invokeStatic(sql_jdbc.clj:54)"
    "driver.sql_jdbc$fn__82291.invoke(sql_jdbc.clj:52)"
    "query_processor.context$executef.invokeStatic(context.clj:59)"
    "query_processor.context$executef.invoke(context.clj:48)"
    "query_processor.context.default$default_runf.invokeStatic(default.clj:68)"
    "query_processor.context.default$default_runf.invoke(default.clj:66)"
    "query_processor.context$runf.invokeStatic(context.clj:45)"
    "query_processor.context$runf.invoke(context.clj:39)"
    "query_processor.reducible$pivot.invokeStatic(reducible.clj:34)"
    "query_processor.reducible$pivot.invoke(reducible.clj:31)"
    "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__47888.invoke(mbql_to_native.clj:25)"
    "query_processor.middleware.check_features$check_features$fn__47002.invoke(check_features.clj:39)"
    "query_processor.middleware.limit$limit$fn__47874.invoke(limit.clj:37)"
    "query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:177)"
    "query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:168)"
    "query_processor.middleware.cache$maybe_return_cached_results$fn__46454.invoke(cache.clj:203)"
    "query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__48134.invoke(optimize_temporal_filters.clj:204)"
    "query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50066.invoke(validate_temporal_bucketing.clj:50)"
    "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__45573.invoke(auto_parse_filter_values.clj:43)"
    "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__41707.invoke(wrap_value_literals.clj:161)"
    "query_processor.middleware.annotate$add_column_info$fn__41582.invoke(annotate.clj:608)"
    "query_processor.middleware.permissions$check_query_permissions$fn__46874.invoke(permissions.clj:81)"
    "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__48995.invoke(pre_alias_aggregations.clj:40)"
    "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__47075.invoke(cumulative_aggregations.clj:60)"
    "query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__49292.invoke(resolve_joined_fields.clj:102)"
    "query_processor.middleware.resolve_joins$resolve_joins$fn__49605.invoke(resolve_joins.clj:171)"
    "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__45149.invoke(add_implicit_joins.clj:190)"
    "query_processor.middleware.large_int_id$convert_id_to_string$fn__47838.invoke(large_int_id.clj:59)"
    "query_processor.middleware.format_rows$format_rows$fn__47819.invoke(format_rows.clj:74)"
    "query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__44443.invoke(add_default_temporal_unit.clj:23)"
    "query_processor.middleware.desugar$desugar$fn__47141.invoke(desugar.clj:21)"
    "query_processor.middleware.binning$update_binning_strategy$fn__45960.invoke(binning.clj:229)"
    "query_processor.middleware.resolve_fields$resolve_fields$fn__46677.invoke(resolve_fields.clj:34)"
    "query_processor.middleware.add_dimension_projections$add_remapping$fn__44798.invoke(add_dimension_projections.clj:312)"
    "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__45027.invoke(add_implicit_clauses.clj:147)"
    "query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__50015.invoke(upgrade_field_literals.clj:40)"
    "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__45312.invoke(add_source_metadata.clj:123)"
    "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__49167.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)"
    "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__45520.invoke(auto_bucket_datetimes.clj:147)"
    "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__46724.invoke(resolve_source_table.clj:45)"
    "query_processor.middleware.parameters$substitute_parameters$fn__48977.invoke(parameters.clj:111)"
    "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__46776.invoke(resolve_referenced.clj:79)"
    "query_processor.middleware.expand_macros$expand_macros$fn__47525.invoke(expand_macros.clj:184)"
    "query_processor.middleware.add_timezone_info$add_timezone_info$fn__45321.invoke(add_timezone_info.clj:15)"
    "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__49968.invoke(splice_params_in_response.clj:32)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49178$fn__49182.invoke(resolve_database_and_driver.clj:31)"
    "driver$do_with_driver.invokeStatic(driver.clj:60)"
    "driver$do_with_driver.invoke(driver.clj:56)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49178.invoke(resolve_database_and_driver.clj:25)"
    "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__47765.invoke(fetch_source_query.clj:274)"
    "query_processor.middleware.store$initialize_store$fn__49977$fn__49978.invoke(store.clj:11)"
    "query_processor.store$do_with_store.invokeStatic(store.clj:44)"
    "query_processor.store$do_with_store.invoke(store.clj:38)"
    "query_processor.middleware.store$initialize_store$fn__49977.invoke(store.clj:10)"
    "query_processor.middleware.validate$validate_query$fn__50022.invoke(validate.clj:10)"
    "query_processor.middleware.normalize_query$normalize$fn__47901.invoke(normalize_query.clj:22)"
    "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__45167.invoke(add_rows_truncated.clj:35)"
    "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49953.invoke(results_metadata.clj:147)"
    "query_processor.middleware.constraints$add_default_userland_constraints$fn__47018.invoke(constraints.clj:42)"
    "query_processor.middleware.process_userland_query$process_userland_query$fn__49064.invoke(process_userland_query.clj:134)"
    "query_processor.middleware.catch_exceptions$catch_exceptions$fn__46958.invoke(catch_exceptions.clj:173)"
    "query_processor.reducible$async_qp$qp_STAR___38246$thunk__38247.invoke(reducible.clj:103)"
    "query_processor.reducible$async_qp$qp_STAR___38246$fn__38249.invoke(reducible.clj:108)"]}
  {:status :failed,
   :class java.sql.SQLException,
   :error "Connections could not be acquired from the underlying database!",
   :stacktrace
   ["com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118)"
    "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:692)"
    "com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
    "--> driver.sql_jdbc.execute$fn__80542.invokeStatic(execute.clj:190)"
    "driver.sql_jdbc.execute$fn__80542.invoke(execute.clj:188)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:475)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:472)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:463)"
    "driver.sql_jdbc$fn__82291.invokeStatic(sql_jdbc.clj:54)"
    "driver.sql_jdbc$fn__82291.invoke(sql_jdbc.clj:52)"
    "query_processor.context$executef.invokeStatic(context.clj:59)"
    "query_processor.context$executef.invoke(context.clj:48)"
    "query_processor.context.default$default_runf.invokeStatic(default.clj:68)"
    "query_processor.context.default$default_runf.invoke(default.clj:66)"
    "query_processor.context$runf.invokeStatic(context.clj:45)"
    "query_processor.context$runf.invoke(context.clj:39)"
    "query_processor.reducible$pivot.invokeStatic(reducible.clj:34)"
    "query_processor.reducible$pivot.invoke(reducible.clj:31)"
    "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__47888.invoke(mbql_to_native.clj:25)"
    "query_processor.middleware.check_features$check_features$fn__47002.invoke(check_features.clj:39)"
    "query_processor.middleware.limit$limit$fn__47874.invoke(limit.clj:37)"
    "query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:177)"
    "query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:168)"
    "query_processor.middleware.cache$maybe_return_cached_results$fn__46454.invoke(cache.clj:203)"
    "query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__48134.invoke(optimize_temporal_filters.clj:204)"
    "query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50066.invoke(validate_temporal_bucketing.clj:50)"
    "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__45573.invoke(auto_parse_filter_values.clj:43)"
    "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__41707.invoke(wrap_value_literals.clj:161)"
    "query_processor.middleware.annotate$add_column_info$fn__41582.invoke(annotate.clj:608)"
    "query_processor.middleware.permissions$check_query_permissions$fn__46874.invoke(permissions.clj:81)"
    "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__48995.invoke(pre_alias_aggregations.clj:40)"
    "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__47075.invoke(cumulative_aggregations.clj:60)"
    "query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__49292.invoke(resolve_joined_fields.clj:102)"
    "query_processor.middleware.resolve_joins$resolve_joins$fn__49605.invoke(resolve_joins.clj:171)"
    "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__45149.invoke(add_implicit_joins.clj:190)"
    "query_processor.middleware.large_int_id$convert_id_to_string$fn__47838.invoke(large_int_id.clj:59)"
    "query_processor.middleware.format_rows$format_rows$fn__47819.invoke(format_rows.clj:74)"
    "query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__44443.invoke(add_default_temporal_unit.clj:23)"
    "query_processor.middleware.desugar$desugar$fn__47141.invoke(desugar.clj:21)"
    "query_processor.middleware.binning$update_binning_strategy$fn__45960.invoke(binning.clj:229)"
    "query_processor.middleware.resolve_fields$resolve_fields$fn__46677.invoke(resolve_fields.clj:34)"
    "query_processor.middleware.add_dimension_projections$add_remapping$fn__44798.invoke(add_dimension_projections.clj:312)"
    "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__45027.invoke(add_implicit_clauses.clj:147)"
    "query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__50015.invoke(upgrade_field_literals.clj:40)"
    "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__45312.invoke(add_source_metadata.clj:123)"
    "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__49167.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)"
    "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__45520.invoke(auto_bucket_datetimes.clj:147)"
    "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__46724.invoke(resolve_source_table.clj:45)"
    "query_processor.middleware.parameters$substitute_parameters$fn__48977.invoke(parameters.clj:111)"
    "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__46776.invoke(resolve_referenced.clj:79)"
    "query_processor.middleware.expand_macros$expand_macros$fn__47525.invoke(expand_macros.clj:184)"
    "query_processor.middleware.add_timezone_info$add_timezone_info$fn__45321.invoke(add_timezone_info.clj:15)"
    "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__49968.invoke(splice_params_in_response.clj:32)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49178$fn__49182.invoke(resolve_database_and_driver.clj:31)"
    "driver$do_with_driver.invokeStatic(driver.clj:60)"
    "driver$do_with_driver.invoke(driver.clj:56)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49178.invoke(resolve_database_and_driver.clj:25)"
    "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__47765.invoke(fetch_source_query.clj:274)"
    "query_processor.middleware.store$initialize_store$fn__49977$fn__49978.invoke(store.clj:11)"
    "query_processor.store$do_with_store.invokeStatic(store.clj:44)"
    "query_processor.store$do_with_store.invoke(store.clj:38)"
    "query_processor.middleware.store$initialize_store$fn__49977.invoke(store.clj:10)"
    "query_processor.middleware.validate$validate_query$fn__50022.invoke(validate.clj:10)"
    "query_processor.middleware.normalize_query$normalize$fn__47901.invoke(normalize_query.clj:22)"
    "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__45167.invoke(add_rows_truncated.clj:35)"
    "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49953.invoke(results_metadata.clj:147)"
    "query_processor.middleware.constraints$add_default_userland_constraints$fn__47018.invoke(constraints.clj:42)"
    "query_processor.middleware.process_userland_query$process_userland_query$fn__49064.invoke(process_userland_query.clj:134)"
    "query_processor.middleware.catch_exceptions$catch_exceptions$fn__46958.invoke(catch_exceptions.clj:173)"
    "query_processor.reducible$async_qp$qp_STAR___38246$thunk__38247.invoke(reducible.clj:103)"
    "query_processor.reducible$async_qp$qp_STAR___38246$fn__38249.invoke(reducible.clj:108)"],
   :state nil}],
 :json_query
 {:constraints {:max-results 10000, :max-results-bare-rows 2000},
  :type :native,
  :middleware {:js-int-to-string? true, :ignore-cached-results? false},
  :native
  {:query
...
5

@flo Okay, so there were no changes to connections between 0.40.1 and 0.40.3.1, so I think other things are at play.
But you can downgrade back to 0.40.1 and see if the problems also occur there.
From your new error log, it definitely seems like it's a problem with the data warehouse connection.

6

Hey @flamber a downgrade back to 0.40.1 didn't help much so you're probably right about the problem source. I'm further investigating it.

7

Okay pretty hilarious... After resetting my Servers Firewall Settings everything is working fine now again. So my Problems had nothing to do with Metabase at all. Sorry for the inconvenience and thanks for your help!

1 Like
8

@flo No worries. I'm used to seeing so many things, so that's why I was sure it was caused by something else, but network issues are extremely tricky to debug from afar, since I don't know the setup.