Metabase 0.48.3, SQL Server 2019, A ResourcePool could not acquire a resource from its primary factory or source

toink · January 19, 2024, 12:55pm

We updated to 0.48.3 and our connection to our SQL Server doesn't work anymore.

Jan 19 13:28:00 srv-bi01 metabase[4064390]: 2024-01-19 13:28:00,695 ERROR middleware.catch-exceptions :: Fehlerverarbeitungsanfrage: Fehler bei der Anmeldung für den Benutzer "***". ClientConnectionId:9b3c78a9-52a6-4a91-8745-c6a21d884b44
Jan 19 13:28:00 srv-bi01 metabase[4064390]: {:database_id 2,
Jan 19 13:28:00 srv-bi01 metabase[4064390]:  :started_at #t "2024-01-19T13:27:36.867042+01:00[Europe/Berlin]",
Jan 19 13:28:00 srv-bi01 metabase[4064390]:  :via
Jan 19 13:28:00 srv-bi01 metabase[4064390]:  [{:status :failed,
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :class com.mchange.v2.resourcepool.CannotAcquireResourceException,
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :error "A ResourcePool could not acquire a resource from its primary factory or source.",
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :stacktrace
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    ["com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1507)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "--> driver.sql_jdbc.execute$fn__78657$_AMPERSAND_f__78658.invoke(execute.clj:333)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78657$fn__78661.invoke(execute.clj:317)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78692.invokeStatic(execute.clj:382)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78692.invoke(execute.clj:380)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:689)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:686)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc$fn__107797.invokeStatic(sql_jdbc.clj:82)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc$fn__107797.invoke(sql_jdbc.clj:80)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$executef.invokeStatic(context.clj:60)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$executef.invoke(context.clj:49)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context.default$default_runf.invokeStatic(default.clj:44)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context.default$default_runf.invoke(default.clj:42)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$runf.invokeStatic(context.clj:46)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$runf.invoke(context.clj:40)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:39)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$identity_qp.invoke(reducible.clj:36)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___71706.invoke(cache.clj:229)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.permissions$check_query_permissions$fn__65626.invoke(permissions.clj:140)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$check_download_permissions_middleware$fn__71527.invoke(enterprise.clj:51)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$maybe_apply_column_level_perms_check_middleware$fn__71537.invoke(enterprise.clj:64)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__70774.invoke(mbql_to_native.clj:24)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor$fn__72834$combined_post_process__72839$combined_post_process_STAR___72840.invoke(query_processor.clj:261)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor$fn__72834$combined_pre_process__72835$combined_pre_process_STAR___72836.invoke(query_processor.clj:258)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65723.invoke(fetch_source_query.clj:303)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617$fn__71621.invoke(resolve_database_and_driver.clj:77)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver$do_with_driver.invokeStatic(driver.clj:94)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver$do_with_driver.invoke(driver.clj:89)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617.invoke(resolve_database_and_driver.clj:76)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.store$initialize_store$fn__66130$fn__66131.invoke(store.clj:14)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:169)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:158)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.store$initialize_store$fn__66130.invoke(store.clj:13)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_database$fn__71614.invoke(resolve_database_and_driver.clj:60)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.normalize_query$normalize$fn__71919.invoke(normalize_query.clj:38)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$fn__71554$handle_audit_app_internal_queries__71555$fn__71557.invoke(enterprise.clj:96)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__71565.invoke(enterprise.clj:103)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.constraints$add_default_userland_constraints$fn__68663.invoke(constraints.clj:81)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.process_userland_query$process_userland_query$fn__71850.invoke(process_userland_query.clj:156)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.catch_exceptions$catch_exceptions$fn__72438.invoke(catch_exceptions.clj:171)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$async_qp$qp_STAR___61171$thunk__61173.invoke(reducible.clj:126)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$async_qp$qp_STAR___61171$fn__61175.invoke(reducible.clj:131)"]}
Jan 19 13:28:00 srv-bi01 metabase[4064390]:   {:status :failed,
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :class java.sql.SQLException,
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :error "Connections could not be acquired from the underlying database!",
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    :stacktrace
Jan 19 13:28:00 srv-bi01 metabase[4064390]:    ["com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:692)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "--> driver.sql_jdbc.execute$fn__78657$_AMPERSAND_f__78658.invoke(execute.clj:333)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78657$fn__78661.invoke(execute.clj:317)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78692.invokeStatic(execute.clj:382)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$fn__78692.invoke(execute.clj:380)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:689)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:686)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc$fn__107797.invokeStatic(sql_jdbc.clj:82)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver.sql_jdbc$fn__107797.invoke(sql_jdbc.clj:80)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$executef.invokeStatic(context.clj:60)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$executef.invoke(context.clj:49)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context.default$default_runf.invokeStatic(default.clj:44)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context.default$default_runf.invoke(default.clj:42)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$runf.invokeStatic(context.clj:46)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.context$runf.invoke(context.clj:40)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:39)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$identity_qp.invoke(reducible.clj:36)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___71706.invoke(cache.clj:229)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.permissions$check_query_permissions$fn__65626.invoke(permissions.clj:140)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$check_download_permissions_middleware$fn__71527.invoke(enterprise.clj:51)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$maybe_apply_column_level_perms_check_middleware$fn__71537.invoke(enterprise.clj:64)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__70774.invoke(mbql_to_native.clj:24)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor$fn__72834$combined_post_process__72839$combined_post_process_STAR___72840.invoke(query_processor.clj:261)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor$fn__72834$combined_pre_process__72835$combined_pre_process_STAR___72836.invoke(query_processor.clj:258)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65723.invoke(fetch_source_query.clj:303)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617$fn__71621.invoke(resolve_database_and_driver.clj:77)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver$do_with_driver.invokeStatic(driver.clj:94)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "driver$do_with_driver.invoke(driver.clj:89)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617.invoke(resolve_database_and_driver.clj:76)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.store$initialize_store$fn__66130$fn__66131.invoke(store.clj:14)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:169)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:158)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.store$initialize_store$fn__66130.invoke(store.clj:13)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.resolve_database_and_driver$resolve_database$fn__71614.invoke(resolve_database_and_driver.clj:60)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.normalize_query$normalize$fn__71919.invoke(normalize_query.clj:38)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$fn__71554$handle_audit_app_internal_queries__71555$fn__71557.invoke(enterprise.clj:96)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__71565.invoke(enterprise.clj:103)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.constraints$add_default_userland_constraints$fn__68663.invoke(constraints.clj:81)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.process_userland_query$process_userland_query$fn__71850.invoke(process_userland_query.clj:156)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.middleware.catch_exceptions$catch_exceptions$fn__72438.invoke(catch_exceptions.clj:171)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$async_qp$qp_STAR___61171$thunk__61173.invoke(reducible.clj:126)"
Jan 19 13:28:00 srv-bi01 metabase[4064390]:     "query_processor.reducible$async_qp$qp_STAR___61171$fn__61175.invoke(reducible.clj:131)"],

We have downgraded to 0.48.0. Here are the specs:

{
  "browser-info": {
    "language": "de",
    "platform": "Win32",
    "userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:121.0) Gecko/20100101 Firefox/121.0",
    "vendor": ""
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.21+9-post-Ubuntu-0ubuntu120.04",
    "java.vendor": "Ubuntu",
    "java.vendor.url": "https://ubuntu.com/",
    "java.version": "11.0.21",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.21+9-post-Ubuntu-0ubuntu120.04",
    "os.name": "Linux",
    "os.version": "5.4.0-169-generic",
    "user.language": "de",
    "user.timezone": "Europe/Berlin"
  },
  "metabase-info": {
    "databases": [
      "mysql",
      "sqlserver",
      "h2"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "12.17 (Ubuntu 12.17-0ubuntu0.20.04.1)"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.6.0"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2023-12-14",
      "tag": "v0.48.0",
      "hash": "f985e19"
    },
    "settings": {
      "report-timezone": "Europe/Berlin"
    }
  }
}

Was something changed here?

Luiggi · January 19, 2024, 1:50pm

absolutely nothing. So it works in 48.0 but not in 48.3?

toink · January 19, 2024, 3:00pm

Yeah, after downgrading everything was fine. I think i'll try the update again.

toink · January 22, 2024, 2:42pm

It's still a problem, 0.48.3 is not usable for us.
Made a bug report:

github.com/metabase/metabase

v0.48.3: SQL Server Issue: After Upgrade: A ResourcePool could not acquire a resource from its primary factory or source.

opened 02:40PM - 22 Jan 24 UTC

ryrun

Type:Bug .Needs Triage

### Describe the bug After upgrading metabase vom v0.48.0 Made a forum post about this: https://discourse.metabase.com/t/metabase-0 ### To Reproduce 1. Metabase v0.48.0 with a working 2. Upgrade to v0.48.3 3. Test some basic queries (select 4. Error are shown, in the log: "A ### Expected behavior Should work like in v0.48.0 ### Logs Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: Jan 19 13:28:00 srv-bi01 metabase[4064390]: ### Information about your Metabase ```JSON { "browser-info": { "language": "de", "platform": "Win32", "userAgent": "Mozilla/5.0 (Windows "vendor": "" }, "system-info": { "file.encoding": "UTF-8", "java.runtime.name": "OpenJDK "java.runtime.version": "11.0.21+9-post "java.vendor": "Ubuntu", "java.vendor.url": "https://ubuntu.com/ "java.version": "11.0.21", "java.vm.name": "OpenJDK 64-Bit "java.vm.version": "11.0.21+9-post-Ubun "os.name": "Linux", "os.version": "5.4.0-169-generic", "user.language": "de", "user.timezone": "Europe/Berlin" }, "metabase-info": { "databases": [ "mysql", "sqlserver", "h2" ], "hosting-env": "unknown", "application-database": "postgres", "application-database-details": { "database": { "name": "PostgreSQL", "version": "12.17 (Ubuntu }, "jdbc-driver": { "name": "PostgreSQL JDBC Driver", "version": "42.6.0" } }, "run-mode": "prod", "version": { "date": "2023-12-14", "tag": "v0.48.0", "hash": "f985e19" }, "settings": { "report-timezone": "Europe/Berlin" } } } ``` ### Severity blocking an upgrade ### Additional context _No response_ to v0.48.3 , we cant …use our SQL Serfer conenction anymore. After downgrading to 0.48.0, everything works fine again. Seems like something was changed. -48-3-sql-server-2019-a-resourcepool-could-not-acquire-a-resource-from-its-primary-factory-or-source/69624 connection to MS SQL Server 2019 Database * from table) ResourcePool could not acquire a resource from its primary factory or source" / "Connections could not be acquired from the underlying database" 2024-01-19 13:28:00,695 ERROR middleware.catch-exceptions :: Fehlerverarbeitungsanfrage: Fehler bei der Anmeldung für den Benutzer "***". ClientConnectionId:9b3c78a9-52a6-4a91-8745-c6a21d884b44 {:database_id 2, :started_at #t "2024-01-19T13:27:36.867042+01:00[Europe/Berlin]", :via [{: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__78657$_AMPERSAND_f__78658.invoke(execute.clj:333)" "driver.sql_jdbc.execute$fn__78657$fn__78661.invoke(execute.clj:317)" "driver.sql_jdbc.execute$fn__78692.invokeStatic(execute.clj:382)" "driver.sql_jdbc.execute$fn__78692.invoke(execute.clj:380)" "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:689)" "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)" "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:686)" "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)" "driver.sql_jdbc$fn__107797.invokeStatic(sql_jdbc.clj:82)" "driver.sql_jdbc$fn__107797.invoke(sql_jdbc.clj:80)" "query_processor.context$executef.invokeStatic(context.clj:60)" "query_processor.context$executef.invoke(context.clj:49)" "query_processor.context.default$default_runf.invokeStatic(default.clj:44)" "query_processor.context.default$default_runf.invoke(default.clj:42)" "query_processor.context$runf.invokeStatic(context.clj:46)" "query_processor.context$runf.invoke(context.clj:40)" "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:39)" "query_processor.reducible$identity_qp.invoke(reducible.clj:36)" "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___71706.invoke(cache.clj:229)" "query_processor.middleware.permissions$check_query_permissions$fn__65626.invoke(permissions.clj:140)" "query_processor.middleware.enterprise$check_download_permissions_middleware$fn__71527.invoke(enterprise.clj:51)" "query_processor.middleware.enterprise$maybe_apply_column_level_perms_check_middleware$fn__71537.invoke(enterprise.clj:64)" "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__70774.invoke(mbql_to_native.clj:24)" "query_processor$fn__72834$combined_post_process__72839$combined_post_process_STAR___72840.invoke(query_processor.clj:261)" "query_processor$fn__72834$combined_pre_process__72835$combined_pre_process_STAR___72836.invoke(query_processor.clj:258)" "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65723.invoke(fetch_source_query.clj:303)" "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617$fn__71621.invoke(resolve_database_and_driver.clj:77)" "driver$do_with_driver.invokeStatic(driver.clj:94)" "driver$do_with_driver.invoke(driver.clj:89)" "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617.invoke(resolve_database_and_driver.clj:76)" "query_processor.middleware.store$initialize_store$fn__66130$fn__66131.invoke(store.clj:14)" "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:169)" "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)" "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:158)" "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)" "query_processor.middleware.store$initialize_store$fn__66130.invoke(store.clj:13)" "query_processor.middleware.resolve_database_and_driver$resolve_database$fn__71614.invoke(resolve_database_and_driver.clj:60)" "query_processor.middleware.normalize_query$normalize$fn__71919.invoke(normalize_query.clj:38)" "query_processor.middleware.enterprise$fn__71554$handle_audit_app_internal_queries__71555$fn__71557.invoke(enterprise.clj:96)" "query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__71565.invoke(enterprise.clj:103)" "query_processor.middleware.constraints$add_default_userland_constraints$fn__68663.invoke(constraints.clj:81)" "query_processor.middleware.process_userland_query$process_userland_query$fn__71850.invoke(process_userland_query.clj:156)" "query_processor.middleware.catch_exceptions$catch_exceptions$fn__72438.invoke(catch_exceptions.clj:171)" "query_processor.reducible$async_qp$qp_STAR___61171$thunk__61173.invoke(reducible.clj:126)" "query_processor.reducible$async_qp$qp_STAR___61171$fn__61175.invoke(reducible.clj:131)"]} {: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__78657$_AMPERSAND_f__78658.invoke(execute.clj:333)" "driver.sql_jdbc.execute$fn__78657$fn__78661.invoke(execute.clj:317)" "driver.sql_jdbc.execute$fn__78692.invokeStatic(execute.clj:382)" "driver.sql_jdbc.execute$fn__78692.invoke(execute.clj:380)" "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:689)" "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)" "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:686)" "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:678)" "driver.sql_jdbc$fn__107797.invokeStatic(sql_jdbc.clj:82)" "driver.sql_jdbc$fn__107797.invoke(sql_jdbc.clj:80)" "query_processor.context$executef.invokeStatic(context.clj:60)" "query_processor.context$executef.invoke(context.clj:49)" "query_processor.context.default$default_runf.invokeStatic(default.clj:44)" "query_processor.context.default$default_runf.invoke(default.clj:42)" "query_processor.context$runf.invokeStatic(context.clj:46)" "query_processor.context$runf.invoke(context.clj:40)" "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:39)" "query_processor.reducible$identity_qp.invoke(reducible.clj:36)" "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___71706.invoke(cache.clj:229)" "query_processor.middleware.permissions$check_query_permissions$fn__65626.invoke(permissions.clj:140)" "query_processor.middleware.enterprise$check_download_permissions_middleware$fn__71527.invoke(enterprise.clj:51)" "query_processor.middleware.enterprise$maybe_apply_column_level_perms_check_middleware$fn__71537.invoke(enterprise.clj:64)" "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__70774.invoke(mbql_to_native.clj:24)" "query_processor$fn__72834$combined_post_process__72839$combined_post_process_STAR___72840.invoke(query_processor.clj:261)" "query_processor$fn__72834$combined_pre_process__72835$combined_pre_process_STAR___72836.invoke(query_processor.clj:258)" "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65723.invoke(fetch_source_query.clj:303)" "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617$fn__71621.invoke(resolve_database_and_driver.clj:77)" "driver$do_with_driver.invokeStatic(driver.clj:94)" "driver$do_with_driver.invoke(driver.clj:89)" "query_processor.middleware.resolve_database_and_driver$resolve_driver_and_database_local_values$fn__71617.invoke(resolve_database_and_driver.clj:76)" "query_processor.middleware.store$initialize_store$fn__66130$fn__66131.invoke(store.clj:14)" "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:169)" "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)" "query_processor.store$do_with_metadata_provider.invokeStatic(store.clj:158)" "query_processor.store$do_with_metadata_provider.invoke(store.clj:150)" "query_processor.middleware.store$initialize_store$fn__66130.invoke(store.clj:13)" "query_processor.middleware.resolve_database_and_driver$resolve_database$fn__71614.invoke(resolve_database_and_driver.clj:60)" "query_processor.middleware.normalize_query$normalize$fn__71919.invoke(normalize_query.clj:38)" "query_processor.middleware.enterprise$fn__71554$handle_audit_app_internal_queries__71555$fn__71557.invoke(enterprise.clj:96)" "query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__71565.invoke(enterprise.clj:103)" "query_processor.middleware.constraints$add_default_userland_constraints$fn__68663.invoke(constraints.clj:81)" "query_processor.middleware.process_userland_query$process_userland_query$fn__71850.invoke(process_userland_query.clj:156)" "query_processor.middleware.catch_exceptions$catch_exceptions$fn__72438.invoke(catch_exceptions.clj:171)" "query_processor.reducible$async_qp$qp_STAR___61171$thunk__61173.invoke(reducible.clj:126)" "query_processor.reducible$async_qp$qp_STAR___61171$fn__61175.invoke(reducible.clj:131)"], installation NT 10.0; Win64; x64; rv:121.0) Gecko/20100101 Firefox/121.0", Runtime Environment", -Ubuntu-0ubuntu120.04", ", Server VM", tu-0ubuntu120.04", 12.17-0ubuntu0.20.04.1)"

toink · January 30, 2024, 1:40pm

Issue was fixed with the new update: 0.48.4