Getting The connection attempt failed

Bug reports
1

Hi, for the last 3-4 days we are facing this in several of our dashboards.. we are using 0.40.1 and haven't changed anything for a few weeks now.
This is how our dashboard looks like at times

image
image1146×674 28.5 KB

on digging, found out about logs but have checked everything on DB level, we have a limit of over 1000+ connections and not more than 100 are being used. at any time.
Here are the logs ->

{:database_id 5,
:started_at #t "2022-06-02T15:24:46.467790Z[GMT]",
: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.(PgConnection.java:225)"
"org.postgresql.Driver.makeConnection(Driver.java:465)"
"org.postgresql.Driver.connect(Driver.java:264)"
"java.sql/java.sql.DriverManager.getConnection(Unknown Source)"
"java.sql/java.sql.DriverManager.getConnection(Unknown Source)"
"--> 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$maybe_return_cached_results$fn__46454.invoke(cache.clj:204)"
"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$maybe_return_cached_results$fn__46454.invoke(cache.clj:204)"
"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
"SELECT to_char(vc.created_at at time zone 'Asia/Kolkata', 'MM/DD/YYYY') AS "Date",\r\n COUNT(vc.id) AS "Leads added"\r\n FROM voice_workflow_campaigncallcontact_view as vc\r\n -- INNER JOIN voice_workflow_campaign as c ON vc.campaign_id=c.id\r\nWHERE \r\n vc.created_at> {{started_at}}::date - '+5:30'::interval\r\n AND vc.created_at<= {{ended_at}}::date - '+5:30'::interval\r\n AND vc.campaign_id ={{campaign_id}}\r\n and vc.is_active=TRUE\r\n and vc.is_test=FALSE\r\nGROUP BY 1\r\nORDER BY 1",
:template-tags
{"started_at"
{:id "3ad2bd01-9694-d154-8eb2-35d6a042c75a",
:name "started_at",
:display-name "Start At",
:type :date,
:required true},
"ended_at"
{:id "ccd82472-5893-b059-5e4d-75118831a864",
:name "ended_at",
:display-name "End At",
:type :date,
:required true},
"campaign_id"
{:id "f03b40eb-e734-41d9-6d2a-13ffa5ca3d71",
:name "campaign_id",
:display-name "Campaign ID",
:type :number,
:required true}}},
:database 5,
:parameters
[{:type "date/single", :value "2021-09-01", :target ["variable" ["template-tag" "started_at"]]}
{:type "date/single", :value "2021-10-01", :target ["variable" ["template-tag" "ended_at"]]}
{:type "id", :value "2155", :target ["variable" ["template-tag" "campaign_id"]]}
{:type "id", :value "3141", :target ["variable" ["template-tag" "voice_mission_id"]]}],
:async? true,
:cache-ttl nil},
:status :failed,
:class java.net.UnknownHostException,
:stacktrace
["java.base/java.net.AbstractPlainSocketImpl.connect(Unknown Source)"
"java.base/java.net.SocksSocketImpl.connect(Unknown Source)"
"java.base/java.net.Socket.connect(Unknown Source)"
"org.postgresql.core.PGStream.createSocket(PGStream.java:231)"
"org.postgresql.core.PGStream.(PGStream.java:95)"
"org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:98)"
"org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:213)"
"org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)"
"org.postgresql.jdbc.PgConnection.(PgConnection.java:225)"
"org.postgresql.Driver.makeConnection(Driver.java:465)"
"org.postgresql.Driver.connect(Driver.java:264)"
"java.sql/java.sql.DriverManager.getConnection(Unknown Source)"
"java.sql/java.sql.DriverManager.getConnection(Unknown Source)"
"--> connection_pool$proxy_data_source$reify__35302.getConnection(connection_pool.clj:29)"],
:context :question,
:error "The connection attempt failed.",
:row_count 0,
:running_time 0,
:data {:rows , :cols }}

2

Hi @Vaibhav
You need to upgrade immediately to a newer release: https://github.com/metabase/metabase/security/advisories/GHSA-vmm4-cwrm-38rj
And then you should consider cycling all passwords.

3

We have been using an alternative solution for log4j, but coming back to the problem, this is happening for some of the API hits and it is very random in nature, everytime we refresh the page out of 10, any 4-7 components are breaking due to this.. will cycling password be helpful in this case?

4

@Vaibhav You are not providing enough logs to tell what is going on, but the stacktrace you provided errors on UnknownHostException, which usually is a DNS problem.
There has been so many changes since 0.40, so try making a backup and upgrade to latest release.
And I'm guessing you're using an older version of Java too, so upgrade that too:
https://www.metabase.com/docs/latest/operations-guide/java-versions.html

5

Got it, will try doing that and get back with the update :slight_smile: is there any other log/logs which i can share to help u understand it better if you help something else might be off.

6

@Vaibhav The problem likely starts before the stacktrace, so you would need to include that.
As well as "Diagnostic Info" from Admin > Troubleshooting.
But just upgrade - there are many other things than Log4j fixed in newer releases.