Hi Team,
Some of My User gets error while running query. It says Connection Could not be acquired. The metabase info and logs report are below please suggest.
Info
{
“browser-info”: {
“language”: “en-US”,
“platform”: “MacIntel”,
“userAgent”: “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.117 Safari/537.36”,
“vendor”: “Google Inc.”
},
“system-info”: {
“java.runtime.name”: “OpenJDK Runtime Environment”,
“java.runtime.version”: “11.0.3+7”,
“java.vendor”: “AdoptOpenJDK”,
“java.vendor.url”: “https://adoptopenjdk.net/”,
“java.version”: “11.0.3”,
“java.vm.name”: “OpenJDK 64-Bit Server VM”,
“java.vm.version”: “11.0.3+7”,
“os.name”: “Linux”,
“os.version”: “4.14.106-97.85.amzn2.x86_64”,
“user.language”: “en”,
“user.timezone”: “US/Pacific”
},
“metabase-info”: {
“databases”: [
“snowflake”
],
“hosting-env”: “unknown”,
“application-database”: “postgres”,
“run-mode”: “prod”,
“version”: {
“date”: “2019-11-19”,
“tag”: “v0.33.6”,
“branch”: “release-0.33.x”,
“hash”: “be1e0e1”
},
“settings”: {
“report-timezone”: null
}
}
}
Error Logs
02-20 07:52:59 DEBUG middleware.log :: GET /api/database 200 254.3 ms (8 DB calls) Jetty threads: 6/50 (2 idle, 0 queued) (113 total active threads) Queries in flight: 0
SQLException:
Message: Connections could not be acquired from the underlying database!
SQLState: null
Error Code: 0
02-20 07:53:30 ERROR sql-jdbc.execute :: nil
02-20 07:53:30 WARN middleware.process-userland-query :: Query failure {: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)”
“clojure.java.jdbc$get_connection.invokeStatic(jdbc.clj:372)”
“clojure.java.jdbc$get_connection.invoke(jdbc.clj:274)”
“clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:833)”
“clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:769)”
“clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:782)”
“clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:769)”
“–> driver.sql_jdbc.execute$do_in_transaction.invokeStatic(execute.clj:247)”
“driver.sql_jdbc.execute$do_in_transaction.invoke(execute.clj:246)”
“driver.sql_jdbc.execute$run_query_without_timezone.invokeStatic(execute.clj:265)”
“driver.sql_jdbc.execute$run_query_without_timezone.invoke(execute.clj:264)”
“driver.sql_jdbc.execute$execute_query$fn__66699.invoke(execute.clj:297)”
“driver.sql_jdbc.execute$do_with_try_catch.invokeStatic(execute.clj:223)”
“driver.sql_jdbc.execute$do_with_try_catch.invoke(execute.clj:217)”
“driver.sql_jdbc.execute$execute_query.invokeStatic(execute.clj:291)”
“driver.sql_jdbc.execute$execute_query.invoke(execute.clj:285)”
“driver.sql_jdbc$fn__67318.invokeStatic(sql_jdbc.clj:44)”
“driver.sql_jdbc$fn__67318.invoke(sql_jdbc.clj:43)”
“query_processor$fn__44023$execute_query__44028$fn__44029.invoke(query_processor.clj:71)”
“query_processor$fn__44023$execute_query__44028.invoke(query_processor.clj:65)”
“query_processor.middleware.mbql_to_native$mbql__GT_native$fn__34284.invoke(mbql_to_native.clj:38)”
“query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__36550.invoke(annotate.clj:541)”
“query_processor.middleware.annotate$add_column_info$fn__36456.invoke(annotate.clj:485)”
“query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__37491.invoke(cumulative_aggregations.clj:57)”
“query_processor.middleware.resolve_joins$resolve_joins$fn__41131.invoke(resolve_joins.clj:184)”
“query_processor.middleware.limit$limit$fn__38092.invoke(limit.clj:19)”
“query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__43890.invoke(results_metadata.clj:87)”
“query_processor.middleware.format_rows$format_rows$fn__38080.invoke(format_rows.clj:26)”
“query_processor.middleware.add_dimension_projections$add_remapping$fn__35043.invoke(add_dimension_projections.clj:232)”
“query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__35684.invoke(add_source_metadata.clj:107)”
“query_processor.middleware.resolve_source_table$resolve_source_tables$fn__41181.invoke(resolve_source_table.clj:46)”
“query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__35531.invoke(add_row_count_and_status.clj:16)”
“query_processor.middleware.driver_specific$process_query_in_context$fn__37567.invoke(driver_specific.clj:12)”
“query_processor.middleware.add_settings$add_settings$fn__35554.invoke(add_settings.clj:45)”
“query_processor.middleware.resolve_driver$resolve_driver$fn__40795.invoke(resolve_driver.clj:22)”
“query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__36881$fn__36882.invoke(bind_effective_timezone.clj:9)”
“util.date$call_with_effective_timezone.invokeStatic(date.clj:88)”
“util.date$call_with_effective_timezone.invoke(date.clj:77)”
“query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__36881.invoke(bind_effective_timezone.clj:8)”
“query_processor.middleware.store$initialize_store$fn__43915$fn__43916.invoke(store.clj:11)”
“query_processor.store$do_with_store.invokeStatic(store.clj:46)”
“query_processor.store$do_with_store.invoke(store.clj:40)”
“query_processor.middleware.store$initialize_store$fn__43915.invoke(store.clj:10)”
“query_processor.middleware.async$async__GT_sync$fn__34195.invoke(async.clj:23)”
“query_processor.middleware.async_wait$runnable$fn__36607.invoke(async_wait.clj:89)”),
:query
{:native
{:query
“SELECT ARTICLE_HEADLINE,\n COUNT(DISTINCT VISIT_ID) VISITS\nFROM SOPHI.PUBLIC.SNOWPLOW_DATA_SUBSET\nWHERE EVENT_DATE_EST = CURRENT_DATE - 1\nAND LOWER(MARKETING_CONTENT) = ‘breakingnews’\nGROUP BY 1\nORDER BY 2 DESC\nLIMIT 10”,
:template-tags {}},
:type “native”,
:parameters [],
:async? true,
:middleware {:add-default-userland-constraints? true, :userland-query? true},
:info
{:executed-by 43,
:context :ad-hoc,
:card-id nil,
:nested? false,
:query-hash [116, 36, -110, -50, -50, 56, -7, -81, 57, 32, -26, -96, -121, 52, 2, 46, -76, 87, -58, -99, 2, 1, 116, -125, 125, -105, -50, 117, -128, 118, -66, 89]},
:constraints {:max-results 10000, :max-results-bare-rows 2000}},
:cause
{:class com.mchange.v2.resourcepool.CannotAcquireResourceException,
:error “A ResourcePool could not acquire a resource from its primary factory or source.”,
:cause
{:class net.snowflake.client.jdbc.SnowflakeSQLException,
:error “JDBC driver not able to connect to Snowflake. Error code: 390102, Message: User temporarily locked. Try again later, or contact your local system administrator…”}}}
02-20 07:53:30 DEBUG middleware.log :: POST /api/dataset 200 [ASYNC: completed] 31.0 s (9 DB calls) Jetty threads: 5/50 (2 idle, 0 queued) (117 total active threads) Queries in flight: 0
02-20 07:54:29 DEBUG middleware.log :: GET /api/util/bug_report_details 200 1.2 ms (1 DB calls) Jetty threads: 6/50 (3 idle, 0 queued) (113 total active threads) Queries in flight: 0