Unsaved Question Query loads but doesn't load once saved

Get Help
1

Hi!

I am coming across a problem with some Metabase questions.
When I write a native SQL question and execute the code, the result loads very quickly but if I save the question and try opening it, the " Something's gone wrong. We've run into an error. You can try refreshing the page, or just go back." message appears.

Here is the diagnostic info:

{
  "browser-info": {
    "language": "fr-FR",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.12+7",
    "java.vendor": "Eclipse Foundation",
    "java.vendor.url": "https://adoptium.net/",
    "java.version": "11.0.12",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.12+7",
    "os.name": "Linux",
    "os.version": "5.14.13+",
    "user.language": "en",
    "user.timezone": "UTC"
  },
  "metabase-info": {
    "databases": [
      "postgres",
      "mysql",
      "googleanalytics",
      "h2"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "9.6.11"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.2.23"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2021-10-21",
      "tag": "v0.41.1",
      "branch": "release-x.41.x",
      "hash": "76aa4a5"
    },
    "settings": {
      "report-timezone": null
    }
  }
}

And here is the EXPLAIN ANALYZE result from my query (as you can see, the execution time is not that long)

Limit (cost=21999.96..22000.00 rows=1 width=130) (actual time=51.974..52.436 rows=639 loops=1)

-> GroupAggregate (cost=21999.96..22000.00 rows=1 width=130) (actual time=51.972..52.394 rows=639 loops=1)

Group Key: paniers.shipment_number, paniers.selling_shop_name, paniers.order_completed_at, paniers.order_requested_delivery_date, paniers.shipped_at, paniers.zone, paniers.delivery_duration, paniers.delivery_slot, "Delivery Jobs".adapter_type, "Delivery Jobs".created_at

-> Sort (cost=21999.96..21999.96 rows=1 width=130) (actual time=51.959..51.996 rows=639 loops=1)

Sort Key: paniers.shipment_number, paniers.selling_shop_name, paniers.order_completed_at, paniers.order_requested_delivery_date, paniers.shipped_at, paniers.zone, paniers.delivery_duration, paniers.delivery_slot, "Delivery Jobs".adapter_type, "Delivery Jobs".created_at

Sort Method: quicksort Memory: 194kB

-> Nested Loop (cost=320.04..21999.95 rows=1 width=130) (actual time=6.497..50.906 rows=639 loops=1)

-> Nested Loop (cost=319.62..21986.00 rows=10 width=116) (actual time=6.470..43.238 rows=677 loops=1)

-> Bitmap Heap Scan on paniers (cost=319.19..20967.16 rows=397 width=100) (actual time=6.441..39.558 rows=644 loops=1)

Recheck Cond: (order_requested_delivery_date >= '2021-09-16 00:00:00+00'::timestamp with time zone)

Filter: (((shipment_state)::text <> 'canceled'::text) AND ((selling_shop_taxon_name)::text = ANY ('{Brasseries,Bistronomie,"Grandes Tables","Tables du Monde"}'::text)))

Rows Removed by Filter: 21808

Heap Blocks: exact=16135

-> Bitmap Index Scan on requested_delivery_date_and_selling_shop_name_on_paniers (cost=0.00..319.09 rows=22689 width=0) (actual time=4.120..4.121 rows=22736 loops=1)

Index Cond: (order_requested_delivery_date >= '2021-09-16 00:00:00+00'::timestamp with time zone)

-> Index Scan using index_stuart_job_shipment_relationships_unique on delivery_jobs_shipments "Delivery Jobs Shipments - Shipment" (cost=0.42..2.56 rows=1 width=24) (actual time=0.005..0.005 rows=1 loops=644)

Index Cond: (spree_shipment_id = paniers.shipment_id)

Filter: (created_at >= '2021-09-16 00:00:00+00'::timestamp with time zone)

Rows Removed by Filter: 0

-> Index Scan using index_delivery_jobs_on_job_id on delivery_jobs "Delivery Jobs" (cost=0.42..1.38 rows=1 width=54) (actual time=0.011..0.011 rows=1 loops=677)

Index Cond: ((job_id)::text = ("Delivery Jobs Shipments - Shipment".delivery_job_id)::text)

Filter: ((created_at >= '2021-09-16 00:00:00+00'::timestamp with time zone) AND ((current_status)::text <> 'canceled'::text))

Rows Removed by Filter: 0

Planning Time: 1.385 ms

Execution Time: 52.575 ms

Could anyone help me to at least find out where the problem is coming from ?

Thank you!

2

Hi @NK_DataAnalyst
I don't think it has anything to do with your query.
But when you see the error, then check for a detailed stacktrace in Admin > Troubleshooting > Logs.
Are you using cache? Admin > Settings > Caching

3

Hi @flamber,

We do not use Caching for the moment. Do you advise us to enable it ?

Here are (I think) the logs related to a question that doesn't load:

> 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__52139.invokeStatic(execute.clj:191)
> 	at metabase.driver.sql_jdbc.execute$fn__52139.invoke(execute.clj:189)
> 	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
> 	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:499)
> 	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)
> 	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)
> 	at metabase.driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)
> 	at metabase.driver.sql_jdbc$fn__85057.invokeStatic(sql_jdbc.clj:54)
> 	at metabase.driver.sql_jdbc$fn__85057.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__49067.invoke(mbql_to_native.clj:25)
> 	at metabase.query_processor.middleware.check_features$check_features$fn__49554.invoke(check_features.clj:39)
> 	at metabase.query_processor.middleware.limit$limit$fn__47440.invoke(limit.clj:37)
> 	at metabase.query_processor.middleware.cache$maybe_return_cached_results$fn__49928.invoke(cache.clj:204)
> 	at metabase.query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__50921.invoke(optimize_temporal_filters.clj:204)
> 	at metabase.query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50965.invoke(validate_temporal_bucketing.clj:50)
> 	at metabase.query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__49124.invoke(auto_parse_filter_values.clj:43)
> 	at metabase.query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__39226.invoke(wrap_value_literals.clj:161)
> 	at metabase.query_processor.middleware.annotate$add_column_info$fn__43657.invoke(annotate.clj:615)
> 	at metabase.query_processor.middleware.permissions$check_query_permissions$fn__45595.invoke(permissions.clj:108)
> 	at metabase.query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__50105.invoke(pre_alias_aggregations.clj:40)
> 	at metabase.query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__45993.invoke(cumulative_aggregations.clj:60)
> 	at metabase.query_processor.middleware.visualization_settings$update_viz_settings$fn__45931.invoke(visualization_settings.clj:63)
> 	at metabase.query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__47038.invoke(resolve_joined_fields.clj:102)
> 	at metabase.query_processor.middleware.resolve_joins$resolve_joins$fn__50691.invoke(resolve_joins.clj:171)
> 	at metabase.query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__50227.invoke(add_implicit_joins.clj:190)
> 	at metabase.query_processor.middleware.large_int_id$convert_id_to_string$fn__47057.invoke(large_int_id.clj:59)
> 	at metabase.query_processor.middleware.format_rows$format_rows$fn__50279.invoke(format_rows.clj:74)
> 	at metabase.query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__46429.invoke(add_default_temporal_unit.clj:23)
> 	at metabase.query_processor.middleware.desugar$desugar$fn__45904.invoke(desugar.clj:21)
> 	at metabase.query_processor.middleware.binning$update_binning_strategy$fn__39126.invoke(binning.clj:229)
> 	at metabase.query_processor.middleware.resolve_fields$resolve_fields$fn__45238.invoke(resolve_fields.clj:34)
> 	at metabase.query_processor.middleware.add_dimension_projections$add_remapping$fn__49479.invoke(add_dimension_projections.clj:314)
> 	at metabase.query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__49777.invoke(add_implicit_clauses.clj:147)
> 	at metabase.query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__47425.invoke(upgrade_field_literals.clj:40)
> 	at metabase.query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__46806.invoke(add_source_metadata.clj:123)
> 	at metabase.query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__50027.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)
> 	at metabase.query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__48376.invoke(auto_bucket_datetimes.clj:147)
> 	at metabase.query_processor.middleware.resolve_source_table$resolve_source_tables$fn__45219.invoke(resolve_source_table.clj:45)
> 	at metabase.query_processor.middleware.parameters$substitute_parameters$fn__48030.invoke(parameters.clj:111)
> 	at metabase.query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__45292.invoke(resolve_referenced.clj:79)
> 	at metabase.query_processor.middleware.expand_macros$expand_macros$fn__51349.invoke(expand_macros.clj:184)
> 	at metabase.query_processor.middleware.add_timezone_info$add_timezone_info$fn__47809.invoke(add_timezone_info.clj:15)
> 	at metabase.query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__50294.invoke(splice_params_in_response.clj:32)
> 	at metabase.query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49788$fn__49792.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__49788.invoke(resolve_database_and_driver.clj:25)
> 	at metabase.query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__45842.invoke(fetch_source_query.clj:274)
> 	at metabase.query_processor.middleware.store$initialize_store$fn__46030$fn__46031.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__46030.invoke(store.clj:10)
> 	at metabase.query_processor.middleware.validate$validate_query$fn__50077.invoke(validate.clj:10)
> 	at metabase.query_processor.middleware.normalize_query$normalize$fn__50084.invoke(normalize_query.clj:22)
> 	at metabase.query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__47755.invoke(add_rows_truncated.clj:35)
> 	at metabase.query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49053.invoke(results_metadata.clj:143)
> 	at metabase.query_processor.reducible$async_qp$qp_STAR___42477$thunk__42478.invoke(reducible.clj:103)
> 	at metabase.query_processor.reducible$async_qp$qp_STAR___42477.invoke(reducible.clj:109)
> 	at metabase.query_processor.reducible$sync_qp$qp_STAR___42486$fn__42489.invoke(reducible.clj:135)
> 	at metabase.query_processor.reducible$sync_qp$qp_STAR___42486.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:669)
> 	at clojure.core$apply.invoke(core.clj:662)
> 	at metabase.query_processor$process_query.invokeStatic(query_processor.clj:152)
> 	at metabase.query_processor$process_query.doInvoke(query_processor.clj:146)
> 	at clojure.lang.RestFn.invoke(RestFn.java:423)
> 	at clojure.lang.Var.invoke(Var.java:388)
> 	at metabase.db.metadata_queries$fn__69319$table_rows_sample__69328$fn__69331.invoke(metadata_queries.clj:144)
> 	at metabase.db.metadata_queries$fn__69319$table_rows_sample__69328.invoke(metadata_queries.clj:131)
> 	at metabase.sync.analyze.fingerprint$fn__69386$fingerprint_table_BANG___69391$fn__69392.invoke(fingerprint.clj:66)
> 	at metabase.sync.analyze.fingerprint$fn__69386$fingerprint_table_BANG___69391.invoke(fingerprint.clj:46)
> 	at metabase.sync.analyze.fingerprint$fn__69562$fingerprint_fields_BANG___69567$fn__69568$fn__69569.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__69562$fingerprint_fields_BANG___69567$fn__69568.invoke(fingerprint.clj:178)
> 	at metabase.sync.analyze.fingerprint$fn__69562$fingerprint_fields_BANG___69567.invoke(fingerprint.clj:174)
> 	at metabase.sync.analyze.fingerprint$fn__69597$fingerprint_fields_for_db_BANG__STAR___69606$fn__69609$fn__69610$fn__69611.invoke(fingerprint.clj:204)
> 	at clojure.lang.PersistentVector.reduce(PersistentVector.java:343)
> 	at clojure.core$reduce.invokeStatic(core.clj:6829)
> 	at clojure.core$reduce.invoke(core.clj:6812)
> 	at metabase.sync.analyze.fingerprint$fn__69597$fingerprint_fields_for_db_BANG__STAR___69606$fn__69609$fn__69610.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__69597$fingerprint_fields_for_db_BANG__STAR___69606$fn__69609.invoke(fingerprint.clj:197)
> 	at metabase.sync.analyze.fingerprint$fn__69597$fingerprint_fields_for_db_BANG__STAR___69606.invoke(fingerprint.clj:186)
> 	at metabase.sync.analyze.fingerprint$fn__69597$fingerprint_fields_for_db_BANG__STAR___69606$fn__69607.invoke(fingerprint.clj:191)
> 	at metabase.sync.analyze.fingerprint$fn__69597$fingerprint_fields_for_db_BANG__STAR___69606.invoke(fingerprint.clj:186)
> 	at metabase.sync.analyze.fingerprint$fn__69639$fingerprint_fields_for_db_BANG___69644$fn__69645.invoke(fingerprint.clj:218)
> 	at metabase.sync.analyze.fingerprint$fn__69639$fingerprint_fields_for_db_BANG___69644.invoke(fingerprint.clj:212)
> 	at metabase.sync.analyze$make_analyze_steps$fn__69952.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:669)
> 	at clojure.core$apply.invoke(core.clj:662)
> 	at metabase.sync.util$fn__40073$run_step_with_metadata__40078$fn__40082$fn__40084.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__40073$run_step_with_metadata__40078$fn__40082.invoke(util.clj:355)
> 	at metabase.sync.util$fn__40073$run_step_with_metadata__40078.invoke(util.clj:350)
> 	at metabase.sync.util$fn__40264$run_sync_operation__40269$fn__40270$fn__40278.invoke(util.clj:451)
> 	at metabase.sync.util$fn__40264$run_sync_operation__40269$fn__40270.invoke(util.clj:449)
> 	at metabase.sync.util$fn__40264$run_sync_operation__40269.invoke(util.clj:443)
> 	at metabase.sync.analyze$fn__69964$analyze_db_BANG___69969$fn__69970$fn__69971.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__5859.invoke(core.clj:2634)
> 	at metabase.driver$fn__24546.invokeStatic(driver.clj:555)
> 	at metabase.driver$fn__24546.invoke(driver.clj:555)
> 	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
> 	at metabase.sync.util$sync_in_context$fn__39985.invoke(util.clj:135)
> 	at metabase.sync.util$with_db_logging_disabled$fn__39982.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__39971.invoke(util.clj:111)
> 	at metabase.sync.util$with_sync_events$fn__39966.invoke(util.clj:85)
> 	at metabase.sync.util$with_duplicate_ops_prevented$fn__39957.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__69964$analyze_db_BANG___69969$fn__69970.invoke(analyze.clj:118)
> 	at metabase.sync.analyze$fn__69964$analyze_db_BANG___69969.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)
> 	... 139 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:223)
> 	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__33598.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.UnknownHostException: bn8psmeorjnlehf1h8hy-postgresql.services.clever-cloud.com
> 	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:220)
> 	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
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:33+01:00 DEBUG metabase.server.middleware.log GET /api/user/current 200 8.6 ms (3 DB calls) App DB connections: 2/15 Jetty threads: 7/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:33+01:00 DEBUG metabase.server.middleware.log GET /api/session/properties 200 6.2 ms (2 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:33+01:00 DEBUG metabase.server.middleware.log GET /api/database 200 9.6 ms (3 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/session/properties 200 6.0 ms (2 DB calls) App DB connections: 3/15 Jetty threads: 8/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/user/current 200 7.2 ms (3 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/database 200 11.1 ms (3 DB calls) App DB connections: 2/15 Jetty threads: 7/50 (32 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/36/query_metadata 200 27.4 ms (10 DB calls) App DB connections: 6/15 Jetty threads: 11/50 (29 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/68/query_metadata 200 34.1 ms (10 DB calls) App DB connections: 5/15 Jetty threads: 11/50 (29 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/67/query_metadata 200 55.6 ms (11 DB calls) App DB connections: 4/15 Jetty threads: 9/50 (29 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/115/query_metadata 200 54.2 ms (10 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (29 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/35/query_metadata 200 69.0 ms (10 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (29 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/93/query_metadata 200 20.4 ms (8 DB calls) App DB connections: 3/15 Jetty threads: 8/50 (30 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:34+01:00 DEBUG metabase.server.middleware.log GET /api/table/113/query_metadata 200 20.1 ms (8 DB calls) App DB connections: 2/15 Jetty threads: 7/50 (30 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:35+01:00 DEBUG metabase.server.middleware.log POST /api/dataset 202 [ASYNC: completed] 435.2 ms (16 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (30 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:36+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 488.1 ms (7 DB calls) App DB connections: 4/15 Jetty threads: 6/50 (30 idle, 0 queued) (169 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:41+01:00 DEBUG metabase.server.middleware.log GET /api/field/604/values 200 289.4 ms (15 DB calls) App DB connections: 2/15 Jetty threads: 8/50 (30 idle, 0 queued) (169 total active threads) Queries in flight: 1 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:41+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 447.2 ms (7 DB calls) App DB connections: 4/15 Jetty threads: 6/50 (30 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 1/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:47+01:00 DEBUG metabase.server.middleware.log GET /api/card/881 200 1.7 mins (10 DB calls) App DB connections: 1/15 Jetty threads: 7/50 (30 idle, 0 queued) (170 total active threads) Queries in flight: 1 (0 queued)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:47+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 441.5 ms (7 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (30 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:49+01:00 DEBUG metabase.server.middleware.log POST /api/dataset 202 [ASYNC: completed] 674.4 ms (16 DB calls) App DB connections: 2/15 Jetty threads: 5/50 (31 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:53+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 475.1 ms (7 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (31 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:39:59+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 509.8 ms (7 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (31 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:40:00+01:00 DEBUG metabase.server.middleware.log POST /api/dataset 202 [ASYNC: completed] 496.0 ms (16 DB calls) App DB connections: 2/15 Jetty threads: 5/50 (31 idle, 0 queued) (170 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T16:40:03+01:00 WARN metabase.sync.util Error fingerprinting Table 598 'tiger.geocode_settings'
4

@NK_DataAnalyst Are you sure that this stacktrace has anything to do with the problem you're having?
It looks like you have network issues, but the stacktrace indicate that it's a problem during sync, which might be caused by the database connection settings (Admin > Databases) has been changed.
It's a problem that we have fixed, but it should not be a problem for regular queries.

There should be a request like POST /api/card/:id/query, when you view an existing question.

5

This time I think I found it @flamber :

> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:56+01:00 DEBUG metabase.server.middleware.log POST /api/card/515/query 202 [ASYNC: completed] 1.2 s (15 DB calls) App DB connections: 2/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 18 (0 queued); postgres DB 2 connections: 14/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:57+01:00 DEBUG metabase.server.middleware.log POST /api/card/509/query 202 [ASYNC: completed] 1.7 s (15 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 17 (0 queued); postgres DB 2 connections: 0/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:57+01:00 DEBUG metabase.server.middleware.log POST /api/card/514/query 202 [ASYNC: completed] 1.8 s (15 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 16 (0 queued); postgres DB 2 connections: 8/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:57+01:00 DEBUG metabase.server.middleware.log POST /api/card/510/query 202 [ASYNC: completed] 2.1 s (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 15 (0 queued); postgres DB 2 connections: 7/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:57+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 2.2 s (17 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 14 (0 queued); postgres DB 2 connections: 12/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:57+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 2.3 s (17 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 13 (0 queued); postgres DB 2 connections: 11/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:58+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 2.4 s (17 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 12 (0 queued); postgres DB 2 connections: 9/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:58+01:00 DEBUG metabase.server.middleware.log POST /api/card/524/query 202 [ASYNC: completed] 2.5 s (12 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 11 (0 queued); postgres DB 2 connections: 10/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:58+01:00 DEBUG metabase.server.middleware.log POST /api/card/523/query 202 [ASYNC: completed] 3.2 s (12 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 11 (0 queued); postgres DB 2 connections: 15/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:59+01:00 DEBUG metabase.server.middleware.log POST /api/card/517/query 202 [ASYNC: completed] 3.5 s (17 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 10 (0 queued); postgres DB 2 connections: 15/15 (3 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:59+01:00 DEBUG metabase.server.middleware.log POST /api/card/518/query 202 [ASYNC: completed] 3.8 s (16 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 9 (0 queued); postgres DB 2 connections: 15/15 (2 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:06:59+01:00 DEBUG metabase.server.middleware.log GET /api/public/card/b42aaf66-42b0-401a-9ccc-ddde9304d30a/query/json 202 [ASYNC: completed] 1.2 s (7 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (169 total active threads) Queries in flight: 8 (0 queued); postgres DB 2 connections: 11/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/510/query 202 [ASYNC: completed] 89.2 ms (15 DB calls) App DB connections: 15/15 Jetty threads: 11/50 (7 idle, 0 queued) (172 total active threads) Queries in flight: 21 (0 queued); postgres DB 2 connections: 8/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/507/query 202 [ASYNC: completed] 123.4 ms (15 DB calls) App DB connections: 10/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 25 (0 queued); postgres DB 2 connections: 10/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/508/query 202 [ASYNC: completed] 129.4 ms (15 DB calls) App DB connections: 11/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 23 (0 queued); postgres DB 2 connections: 9/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/512/query 202 [ASYNC: completed] 112.2 ms (15 DB calls) App DB connections: 11/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 23 (0 queued); postgres DB 2 connections: 11/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/513/query 202 [ASYNC: completed] 113.3 ms (15 DB calls) App DB connections: 10/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 22 (0 queued); postgres DB 2 connections: 10/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/515/query 202 [ASYNC: completed] 115.5 ms (15 DB calls) App DB connections: 9/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 21 (0 queued); postgres DB 2 connections: 13/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/509/query 202 [ASYNC: completed] 127.4 ms (15 DB calls) App DB connections: 9/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 20 (0 queued); postgres DB 2 connections: 14/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 132.5 ms (17 DB calls) App DB connections: 9/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 19 (0 queued); postgres DB 2 connections: 12/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/511/query 202 [ASYNC: completed] 152.9 ms (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 18 (0 queued); postgres DB 2 connections: 15/15 (1 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/514/query 202 [ASYNC: completed] 118.5 ms (15 DB calls) App DB connections: 4/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 17 (0 queued); postgres DB 2 connections: 15/15 (10 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 160.9 ms (17 DB calls) App DB connections: 5/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 16 (0 queued); postgres DB 2 connections: 15/15 (8 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/517/query 202 [ASYNC: completed] 182.1 ms (17 DB calls) App DB connections: 4/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 15 (0 queued); postgres DB 2 connections: 15/15 (7 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/506/query 202 [ASYNC: completed] 184.2 ms (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 14 (0 queued); postgres DB 2 connections: 15/15 (6 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:00+01:00 DEBUG metabase.server.middleware.log POST /api/card/516/query 202 [ASYNC: completed] 214.1 ms (17 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (11 idle, 0 queued) (176 total active threads) Queries in flight: 13 (0 queued); postgres DB 2 connections: 15/15 (5 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/524/query 202 [ASYNC: completed] 1.4 s (13 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 12 (0 queued); postgres DB 2 connections: 15/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/523/query 202 [ASYNC: completed] 1.4 s (13 DB calls) App DB connections: 4/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 11 (0 queued); postgres DB 2 connections: 15/15 (2 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/521/query 202 [ASYNC: completed] 1.5 s (13 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 10 (0 queued); postgres DB 2 connections: 15/15 (9 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/508/query 202 [ASYNC: completed] 6.0 s (16 DB calls) App DB connections: 5/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 9 (0 queued); postgres DB 2 connections: 1/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/522/query 202 [ASYNC: completed] 1.5 s (13 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 8 (0 queued); postgres DB 2 connections: 15/15 (4 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:01+01:00 DEBUG metabase.server.middleware.log POST /api/card/507/query 202 [ASYNC: completed] 6.3 s (15 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 7 (0 queued); postgres DB 2 connections: 3/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/518/query 202 [ASYNC: completed] 1.9 s (16 DB calls) App DB connections: 3/15 Jetty threads: 5/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 6 (0 queued); postgres DB 2 connections: 15/15 (3 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/511/query 202 [ASYNC: completed] 6.4 s (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 5 (0 queued); postgres DB 2 connections: 5/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/513/query 202 [ASYNC: completed] 6.5 s (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 4 (0 queued); postgres DB 2 connections: 4/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/506/query 202 [ASYNC: completed] 6.5 s (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 3 (0 queued); postgres DB 2 connections: 2/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/512/query 202 [ASYNC: completed] 6.6 s (15 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 2 (0 queued); postgres DB 2 connections: 6/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/521/query 202 [ASYNC: completed] 6.6 s (12 DB calls) App DB connections: 3/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 1 (0 queued); postgres DB 2 connections: 13/15 (0 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:02+01:00 DEBUG metabase.server.middleware.log POST /api/card/522/query 202 [ASYNC: canceled] 7.0 s (11 DB calls) App DB connections: 1/15 Jetty threads: 6/50 (12 idle, 0 queued) (176 total active threads) Queries in flight: 0 (0 queued); postgres DB 2 connections: 15/15 (1 threads blocked)
> [271766ea-bc69-4670-8eeb-970b726ef1ac] 2021-11-02T17:07:03+01:00 ERROR metabase.query-processor.middleware.catch-exceptions Error processing query: null
> {:database_id 2,
>  :started_at #t "2021-11-02T16:06:55.739225Z[UTC]",
>  :via
>  [{:status :failed,
>    :class org.eclipse.jetty.io.EofException,
>    :error nil,
>    :stacktrace
>    ["org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279)"
>     "org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)"
>     "org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277)"
>     "org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381)"
>     "org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:826)"
>     "org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)"
>     "org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)"
>     "org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550)"
>     "org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:915)"
>     "org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987)"
>     "org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285)"
>     "org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:269)"
>     "org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:749)"
>     "java.base/java.util.zip.DeflaterOutputStream.flush(DeflaterOutputStream.java:282)"
>     "--> async.streaming_response$delay_output_stream$fn__25245.invoke(streaming_response.clj:119)"
>     "async.streaming_response.proxy$java.io.OutputStream$ff19274a.flush(Unknown Source)"
>     "query_processor.streaming.json$fn$reify__37226.write_row_BANG_(json.clj:71)"
>     "query_processor.streaming$streaming_rff$fn__37976$fn__37981.invoke(streaming.clj:110)"
>     "query_processor.middleware.process_userland_query$add_and_save_execution_info_xform_BANG_$execution_info_rf_STAR___50054.invoke(process_userland_query.clj:101)"
>     "query_processor.reducible$combine_additional_reducing_fns$fn__42500.invoke(reducible.clj:215)"
>     "query_processor.middleware.add_rows_truncated$add_rows_truncated_xform$fn__47750.invoke(add_rows_truncated.clj:27)"
>     "query_processor.middleware.format_rows$format_rows_xform$fn__50272.invoke(format_rows.clj:68)"
>     "query_processor.reducible$combine_additional_reducing_fns$fn__42500.invoke(reducible.clj:215)"
>     "query_processor.middleware.limit$limit_xform$fn__47437.invoke(limit.clj:24)"
>     "query_processor.reducible$reducible_rows$reify__42493.reduce(reducible.clj:159)"
>     "query_processor.context.default$default_reducef$fn__42389.invoke(default.clj:58)"
>     "query_processor.context.default$default_reducef.invokeStatic(default.clj:57)"
>     "query_processor.context.default$default_reducef.invoke(default.clj:48)"
>     "query_processor.context$reducef.invokeStatic(context.clj:69)"
>     "query_processor.context$reducef.invoke(context.clj:62)"
>     "query_processor.context.default$default_runf$respond_STAR___42393.invoke(default.clj:69)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:509)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>     "driver.sql_jdbc$fn__85057.invokeStatic(sql_jdbc.clj:54)"
>     "driver.sql_jdbc$fn__85057.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__49067.invoke(mbql_to_native.clj:25)"
>     "query_processor.middleware.check_features$check_features$fn__49554.invoke(check_features.clj:39)"
>     "query_processor.middleware.limit$limit$fn__47440.invoke(limit.clj:37)"
>     "query_processor.middleware.cache$maybe_return_cached_results$fn__49928.invoke(cache.clj:204)"
>     "query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__50921.invoke(optimize_temporal_filters.clj:204)"
>     "query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50965.invoke(validate_temporal_bucketing.clj:50)"
>     "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__49124.invoke(auto_parse_filter_values.clj:43)"
>     "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__39226.invoke(wrap_value_literals.clj:161)"
>     "query_processor.middleware.annotate$add_column_info$fn__43657.invoke(annotate.clj:615)"
>     "query_processor.middleware.permissions$check_query_permissions$fn__45595.invoke(permissions.clj:108)"
>     "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__50105.invoke(pre_alias_aggregations.clj:40)"
>     "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__45993.invoke(cumulative_aggregations.clj:60)"
>     "query_processor.middleware.visualization_settings$update_viz_settings$fn__45931.invoke(visualization_settings.clj:63)"
>     "query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__47038.invoke(resolve_joined_fields.clj:102)"
>     "query_processor.middleware.resolve_joins$resolve_joins$fn__50691.invoke(resolve_joins.clj:171)"
>     "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__50227.invoke(add_implicit_joins.clj:190)"
>     "query_processor.middleware.large_int_id$convert_id_to_string$fn__47057.invoke(large_int_id.clj:59)"
>     "query_processor.middleware.format_rows$format_rows$fn__50279.invoke(format_rows.clj:74)"
>     "query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__46429.invoke(add_default_temporal_unit.clj:23)"
>     "query_processor.middleware.desugar$desugar$fn__45904.invoke(desugar.clj:21)"
>     "query_processor.middleware.binning$update_binning_strategy$fn__39126.invoke(binning.clj:229)"
>     "query_processor.middleware.resolve_fields$resolve_fields$fn__45238.invoke(resolve_fields.clj:34)"
>     "query_processor.middleware.add_dimension_projections$add_remapping$fn__49479.invoke(add_dimension_projections.clj:312)"
>     "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__49777.invoke(add_implicit_clauses.clj:147)"
>     "query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__47425.invoke(upgrade_field_literals.clj:40)"
>     "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__46806.invoke(add_source_metadata.clj:123)"
>     "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__50027.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)"
>     "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__48376.invoke(auto_bucket_datetimes.clj:147)"
>     "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__45219.invoke(resolve_source_table.clj:45)"
>     "query_processor.middleware.parameters$substitute_parameters$fn__48030.invoke(parameters.clj:111)"
>     "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__45292.invoke(resolve_referenced.clj:79)"
>     "query_processor.middleware.expand_macros$expand_macros$fn__51349.invoke(expand_macros.clj:184)"
>     "query_processor.middleware.add_timezone_info$add_timezone_info$fn__47809.invoke(add_timezone_info.clj:15)"
>     "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__50294.invoke(splice_params_in_response.clj:32)"
>     "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49788$fn__49792.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__49788.invoke(resolve_database_and_driver.clj:25)"
>     "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__45842.invoke(fetch_source_query.clj:274)"
>     "query_processor.middleware.store$initialize_store$fn__46030$fn__46031.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__46030.invoke(store.clj:10)"
>     "query_processor.middleware.validate$validate_query$fn__50077.invoke(validate.clj:10)"
>     "query_processor.middleware.normalize_query$normalize$fn__50084.invoke(normalize_query.clj:22)"
>     "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__47755.invoke(add_rows_truncated.clj:35)"
>     "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49053.invoke(results_metadata.clj:147)"
>     "query_processor.middleware.constraints$add_default_userland_constraints$fn__47773.invoke(constraints.clj:42)"
>     "query_processor.middleware.process_userland_query$process_userland_query$fn__50063.invoke(process_userland_query.clj:146)"
>     "query_processor.middleware.catch_exceptions$catch_exceptions$fn__50374.invoke(catch_exceptions.clj:169)"
>     "query_processor.reducible$async_qp$qp_STAR___42477$thunk__42478.invoke(reducible.clj:103)"
>     "query_processor.reducible$async_qp$qp_STAR___42477$fn__42480.invoke(reducible.clj:108)"]}
>   {:status :failed,
>    :class clojure.lang.ExceptionInfo,
>    :error "Error reducing result rows",
>    :stacktrace
>    ["--> query_processor.context.default$default_reducef$fn__42389.invoke(default.clj:60)"
>     "query_processor.context.default$default_reducef.invokeStatic(default.clj:57)"
>     "query_processor.context.default$default_reducef.invoke(default.clj:48)"
>     "query_processor.context$reducef.invokeStatic(context.clj:69)"
>     "query_processor.context$reducef.invoke(context.clj:62)"
>     "query_processor.context.default$default_runf$respond_STAR___42393.invoke(default.clj:69)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:509)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)"
>     "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>     "driver.sql_jdbc$fn__85057.invokeStatic(sql_jdbc.clj:54)"
>     "driver.sql_jdbc$fn__85057.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__49067.invoke(mbql_to_native.clj:25)"
>     "query_processor.middleware.check_features$check_features$fn__49554.invoke(check_features.clj:39)"
>     "query_processor.middleware.limit$limit$fn__47440.invoke(limit.clj:37)"
>     "query_processor.middleware.cache$maybe_return_cached_results$fn__49928.invoke(cache.clj:204)"
>     "query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__50921.invoke(optimize_temporal_filters.clj:204)"
>     "query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50965.invoke(validate_temporal_bucketing.clj:50)"
>     "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__49124.invoke(auto_parse_filter_values.clj:43)"
>     "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__39226.invoke(wrap_value_literals.clj:161)"
>     "query_processor.middleware.annotate$add_column_info$fn__43657.invoke(annotate.clj:615)"
>     "query_processor.middleware.permissions$check_query_permissions$fn__45595.invoke(permissions.clj:108)"
>     "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__50105.invoke(pre_alias_aggregations.clj:40)"
>     "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__45993.invoke(cumulative_aggregations.clj:60)"
>     "query_processor.middleware.visualization_settings$update_viz_settings$fn__45931.invoke(visualization_settings.clj:63)"
>     "query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__47038.invoke(resolve_joined_fields.clj:102)"
>     "query_processor.middleware.resolve_joins$resolve_joins$fn__50691.invoke(resolve_joins.clj:171)"
>     "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__50227.invoke(add_implicit_joins.clj:190)"
>     "query_processor.middleware.large_int_id$convert_id_to_string$fn__47057.invoke(large_int_id.clj:59)"
>     "query_processor.middleware.format_rows$format_rows$fn__50279.invoke(format_rows.clj:74)"
>     "query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__46429.invoke(add_default_temporal_unit.clj:23)"
>     "query_processor.middleware.desugar$desugar$fn__45904.invoke(desugar.clj:21)"
>     "query_processor.middleware.binning$update_binning_strategy$fn__39126.invoke(binning.clj:229)"
>     "query_processor.middleware.resolve_fields$resolve_fields$fn__45238.invoke(resolve_fields.clj:34)"
>     "query_processor.middleware.add_dimension_projections$add_remapping$fn__49479.invoke(add_dimension_projections.clj:312)"
>     "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__49777.invoke(add_implicit_clauses.clj:147)"
>     "query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__47425.invoke(upgrade_field_literals.clj:40)"
>     "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__46806.invoke(add_source_metadata.clj:123)"
>     "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__50027.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)"
>     "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__48376.invoke(auto_bucket_datetimes.clj:147)"
>     "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__45219.invoke(resolve_source_table.clj:45)"
>     "query_processor.middleware.parameters$substitute_parameters$fn__48030.invoke(parameters.clj:111)"
>     "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__45292.invoke(resolve_referenced.clj:79)"
>     "query_processor.middleware.expand_macros$expand_macros$fn__51349.invoke(expand_macros.clj:184)"
>     "query_processor.middleware.add_timezone_info$add_timezone_info$fn__47809.invoke(add_timezone_info.clj:15)"
>     "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__50294.invoke(splice_params_in_response.clj:32)"
>     "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49788$fn__49792.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__49788.invoke(resolve_database_and_driver.clj:25)"
>     "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__45842.invoke(fetch_source_query.clj:274)"
>     "query_processor.middleware.store$initialize_store$fn__46030$fn__46031.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__46030.invoke(store.clj:10)"
>     "query_processor.middleware.validate$validate_query$fn__50077.invoke(validate.clj:10)"
>     "query_processor.middleware.normalize_query$normalize$fn__50084.invoke(normalize_query.clj:22)"
>     "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__47755.invoke(add_rows_truncated.clj:35)"
>     "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49053.invoke(results_metadata.clj:147)"
>     "query_processor.middleware.constraints$add_default_userland_constraints$fn__47773.invoke(constraints.clj:42)"
>     "query_processor.middleware.process_userland_query$process_userland_query$fn__50063.invoke(process_userland_query.clj:146)"
>     "query_processor.middleware.catch_exceptions$catch_exceptions$fn__50374.invoke(catch_exceptions.clj:169)"
>     "query_processor.reducible$async_qp$qp_STAR___42477$thunk__42478.invoke(reducible.clj:103)"
>     "query_processor.reducible$async_qp$qp_STAR___42477$fn__42480.invoke(reducible.clj:108)"],
>    :error_type :qp,
>    :ex-data {:type :qp}}],
>  :error_type :qp,
>  :json_query
>  {:constraints {:max-results 10000, :max-results-bare-rows 2000},
>   :type :native,
>   :middleware {:js-int-to-string? true, :ignore-cached-results? false, :process-viz-settings? false},
>   :native
>   {:query
>    "SELECT \n  paniers.shop_name\t                         AS \"shop_name\",\n  COUNT(DISTINCT paniers.preparation_number) AS \"preparation_count\"\n\nFROM paniers\nWHERE paniers.shipment_state <> 'canceled'\nAND paniers.preparation_id IS NOT NULL\nAND {{period}}\nAND {{app_name}}\nAND {{zone}}\nAND {{account_manager_email}}\nAND (paniers.preparation_id IS NOT NULL)\nGROUP BY paniers.shop_name\nORDER BY \"preparation_count\" DESC\n",
>    :template-tags
>    {"period"
>     {:id "a7a391a6-d175-e329-987a-75fad58306ec",
>      :name "period",
>      :display-name "Period",
>      :type :dimension,
>      :dimension [:field 3040 nil],
>      :widget-type :date/month-year},
>     "app_name"
>     {:id "1d00331c-4d42-e52c-21c2-3d3d2d984dbd",
>      :name "app_name",
>      :display-name "App name",
>      :type :dimension,
>      :dimension [:field 3079 nil],
>      :widget-type :category},
>     "zone"
>     {:id "ae4dc9b9-1409-dcd4-2f49-4e3dea47040a",
>      :name "zone",
>      :display-name "Zone",
>      :type :dimension,
>      :dimension [:field 3083 nil],
>      :widget-type :category},
>     "account_manager_email"
>     {:id "7c813523-d515-e0d4-ace7-7dccc1bdc353",
>      :name "account_manager_email",
>      :display-name "Account manager email",
>      :type :dimension,
>      :dimension [:field 3158 nil],
>      :widget-type :category}}},
>   :database 2,
>   :parameters [],
>   :async? true,
>   :cache-ttl nil},
>  :status :failed,
>  :class java.io.IOException,
>  :stacktrace
>  ["java.base/sun.nio.ch.FileDispatcherImpl.writev0(Native Method)"
>   "java.base/sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51)"
>   "java.base/sun.nio.ch.IOUtil.write(IOUtil.java:182)"
>   "java.base/sun.nio.ch.IOUtil.write(IOUtil.java:130)"
>   "java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:493)"
>   "java.base/java.nio.channels.SocketChannel.write(SocketChannel.java:507)"
>   "org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:273)"
>   "org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)"
>   "org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277)"
>   "org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381)"
>   "org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:826)"
>   "org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)"
>   "org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)"
>   "org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550)"
>   "org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:915)"
>   "org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987)"
>   "org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285)"
>   "org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:269)"
>   "org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:749)"
>   "java.base/java.util.zip.DeflaterOutputStream.flush(DeflaterOutputStream.java:282)"
>   "--> async.streaming_response$delay_output_stream$fn__25245.invoke(streaming_response.clj:119)"
>   "async.streaming_response.proxy$java.io.OutputStream$ff19274a.flush(Unknown Source)"
>   "query_processor.streaming.json$fn$reify__37226.write_row_BANG_(json.clj:71)"
>   "query_processor.streaming$streaming_rff$fn__37976$fn__37981.invoke(streaming.clj:110)"
>   "query_processor.middleware.process_userland_query$add_and_save_execution_info_xform_BANG_$execution_info_rf_STAR___50054.invoke(process_userland_query.clj:101)"
>   "query_processor.reducible$combine_additional_reducing_fns$fn__42500.invoke(reducible.clj:215)"
>   "query_processor.middleware.add_rows_truncated$add_rows_truncated_xform$fn__47750.invoke(add_rows_truncated.clj:27)"
>   "query_processor.middleware.format_rows$format_rows_xform$fn__50272.invoke(format_rows.clj:68)"
>   "query_processor.reducible$combine_additional_reducing_fns$fn__42500.invoke(reducible.clj:215)"
>   "query_processor.middleware.limit$limit_xform$fn__47437.invoke(limit.clj:24)"
>   "query_processor.reducible$reducible_rows$reify__42493.reduce(reducible.clj:159)"
>   "query_processor.context.default$default_reducef$fn__42389.invoke(default.clj:58)"
>   "query_processor.context.default$default_reducef.invokeStatic(default.clj:57)"
>   "query_processor.context.default$default_reducef.invoke(default.clj:48)"
>   "query_processor.context$reducef.invokeStatic(context.clj:69)"
>   "query_processor.context$reducef.invoke(context.clj:62)"
>   "query_processor.context.default$default_runf$respond_STAR___42393.invoke(default.clj:69)"
>   "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:509)"
>   "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>   "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)"
>   "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:487)"
>   "driver.sql_jdbc$fn__85057.invokeStatic(sql_jdbc.clj:54)"
>   "driver.sql_jdbc$fn__85057.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__49067.invoke(mbql_to_native.clj:25)"
>   "query_processor.middleware.check_features$check_features$fn__49554.invoke(check_features.clj:39)"
>   "query_processor.middleware.limit$limit$fn__47440.invoke(limit.clj:37)"
>   "query_processor.middleware.cache$maybe_return_cached_results$fn__49928.invoke(cache.clj:204)"
>   "query_processor.middleware.optimize_temporal_filters$optimize_temporal_filters$fn__50921.invoke(optimize_temporal_filters.clj:204)"
>   "query_processor.middleware.validate_temporal_bucketing$validate_temporal_bucketing$fn__50965.invoke(validate_temporal_bucketing.clj:50)"
>   "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__49124.invoke(auto_parse_filter_values.clj:43)"
>   "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__39226.invoke(wrap_value_literals.clj:161)"
>   "query_processor.middleware.annotate$add_column_info$fn__43657.invoke(annotate.clj:615)"
>   "query_processor.middleware.permissions$check_query_permissions$fn__45595.invoke(permissions.clj:108)"
>   "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__50105.invoke(pre_alias_aggregations.clj:40)"
>   "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__45993.invoke(cumulative_aggregations.clj:60)"
>   "query_processor.middleware.visualization_settings$update_viz_settings$fn__45931.invoke(visualization_settings.clj:63)"
>   "query_processor.middleware.resolve_joined_fields$resolve_joined_fields$fn__47038.invoke(resolve_joined_fields.clj:102)"
>   "query_processor.middleware.resolve_joins$resolve_joins$fn__50691.invoke(resolve_joins.clj:171)"
>   "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__50227.invoke(add_implicit_joins.clj:190)"
>   "query_processor.middleware.large_int_id$convert_id_to_string$fn__47057.invoke(large_int_id.clj:59)"
>   "query_processor.middleware.format_rows$format_rows$fn__50279.invoke(format_rows.clj:74)"
>   "query_processor.middleware.add_default_temporal_unit$add_default_temporal_unit$fn__46429.invoke(add_default_temporal_unit.clj:23)"
>   "query_processor.middleware.desugar$desugar$fn__45904.invoke(desugar.clj:21)"
>   "query_processor.middleware.binning$update_binning_strategy$fn__39126.invoke(binning.clj:229)"
>   "query_processor.middleware.resolve_fields$resolve_fields$fn__45238.invoke(resolve_fields.clj:34)"
>   "query_processor.middleware.add_dimension_projections$add_remapping$fn__49479.invoke(add_dimension_projections.clj:312)"
>   "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__49777.invoke(add_implicit_clauses.clj:147)"
>   "query_processor.middleware.upgrade_field_literals$upgrade_field_literals$fn__47425.invoke(upgrade_field_literals.clj:40)"
>   "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__46806.invoke(add_source_metadata.clj:123)"
>   "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__50027.invoke(reconcile_breakout_and_order_by_bucketing.clj:100)"
>   "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__48376.invoke(auto_bucket_datetimes.clj:147)"
>   "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__45219.invoke(resolve_source_table.clj:45)"
>   "query_processor.middleware.parameters$substitute_parameters$fn__48030.invoke(parameters.clj:111)"
>   "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__45292.invoke(resolve_referenced.clj:79)"
>   "query_processor.middleware.expand_macros$expand_macros$fn__51349.invoke(expand_macros.clj:184)"
>   "query_processor.middleware.add_timezone_info$add_timezone_info$fn__47809.invoke(add_timezone_info.clj:15)"
>   "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__50294.invoke(splice_params_in_response.clj:32)"
>   "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__49788$fn__49792.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__49788.invoke(resolve_database_and_driver.clj:25)"
>   "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__45842.invoke(fetch_source_query.clj:274)"
>   "query_processor.middleware.store$initialize_store$fn__46030$fn__46031.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__46030.invoke(store.clj:10)"
>   "query_processor.middleware.validate$validate_query$fn__50077.invoke(validate.clj:10)"
>   "query_processor.middleware.normalize_query$normalize$fn__50084.invoke(normalize_query.clj:22)"
>   "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__47755.invoke(add_rows_truncated.clj:35)"
>   "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__49053.invoke(results_metadata.clj:147)"
>   "query_processor.middleware.constraints$add_default_userland_constraints$fn__47773.invoke(constraints.clj:42)"
>   "query_processor.middleware.process_userland_query$process_userland_query$fn__50063.invoke(process_userland_query.clj:146)"
>   "query_processor.middleware.catch_exceptions$catch_exceptions$fn__50374.invoke(catch_exceptions.clj:169)"
>   "query_processor.reducible$async_qp$qp_STAR___42477$thunk__42478.invoke(reducible.clj:103)"
>   "query_processor.reducible$async_qp$qp_STAR___42477$fn__42480.invoke(reducible.clj:108)"],
>  :card_id 522,
>  :context :question,
>  :error "Broken pipe",
>  :row_count 0,
>  :running_time 0,
>  :data {:rows [], :cols []}}
6

@NK_DataAnalyst You have something that closes the connection between the browser and Metabase.

/api/card/522/query 202 [ASYNC: canceled] 7.0 s

Likely a reverse-proxy (firewall, antivirus, CDN, load-balancer, etc):
https://www.metabase.com/docs/latest/troubleshooting-guide/proxies.html

7

Hi @flamber,

Thank you for your kind support.

Yes, we have not 1 but 2 reverse proxies which both cut the connection after 30 seconds, so I think this is not the issue as the example you use is canceled after 7 seconds.
One of them is Cloudflare, but WAF is not reporting any events from my IP address, so once again, I think this is not the issue.

I've tested with a very small query SELECT name FROM spree_zones which returns 16 rows in under 10 ms response time both from the metabase interface, and from the metabase server inside an SSH session.
So network does not seems to be the issue either.

What is really really strange is the fact that this works perfectly on this scenario :

Ask a question > Native query > Production database > SELECT name FROM spree_zones

but not if I save this question and view it from /question/885 which will crash each time after 30 seconds (my reverse proxies kills it),
and the logs says that it take between 1.6 and 2.1 minute to complete!

No stacktrace is visible in the log, only this line:

DEBUG metabase.server.middleware.log GET /api/card/885 200 2.0 mins (10 DB calls) App DB connections: 0/15 Jetty threads: 5/50 (6 idle, 0 queued) (123 total active threads) Queries in flight: 0 (0 queued)

Both metabase and database servers seem to have plenty of available resources:
metabase server:

  • CPU usage < 10%
  • RAM usage < 30%

BDD server:

  • CPU usage < 10%
  • RAM usage < 20%

I'm not sure if this is relevent, but we're running as a jar file on a 8GB host with the following options:

  • JAVA_OPTS=-Xms 6g

Do you have any idea of what might cause this kind of delay except network issues ?

8

@NK_DataAnalyst You're seeing this issue: https://github.com/metabase/metabase/issues/18759

9

Hi @flamber,
Thank you for sharing the github issue. It seems that we are having the same issue.
However, were the fixes related to this issue part of the 0.41.2 release?
We have updated to the latest version but still experience the issue.
Thank you for your help

10

@NK_DataAnalyst
Please post "Diagnostic Info" from Admin > Troubleshooting - again.
I only reason I referenced that issue was because of ... /api/card/885 200 2.0 mins ..., which you should not be seeing anymore, otherwise post your logs - again.

11

Hello @flamber, we found the issue. Just wanted to share with you in case it happens to others.
It was the query_execution table which contains all our Metabase query history. We truncated the table (it had +19M rows) and now everything works perfectly! Thank you for trying to help anyway!

12

@NK_DataAnalyst Thank you! On my test instance, I've "only" generated 1 million rows, but I'm starting to see some slowdown. We'll tweak this.

Just for reference - I've created an issue to track:
https://github.com/metabase/metabase/issues/19053 - upvote by clicking :+1: on the first post