AsyncContext timeout for queries longer than 10 minutes

I am running a query that takes more than 10 minutes and it ends with Your query took too long message. I have tried running this on chrome and firefox, even with just IP address.

  • I am running a reverse proxy through nginx, below is its configuration
server {
    listen 443 ssl;
    server_name domain.com;

    access_log /var/log/nginx/access.log;
    error_log /var/log/nginx/error.log;

    ssl_certificate domain.com/fullchain.pem;
    ssl_certificate_key domain.com/privkey.pem;

    ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
    ssl_ciphers HIGH:!aNULL:!MD5;

    client_max_body_size 20M;

    keepalive_timeout 3600;

    location / {
        proxy_pass http://metabase/;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_read_timeout 3600;
        proxy_connect_timeout 3600;
        proxy_send_timeout 3600; 
    }
}
  • Metabase further connects to to postgres. Below are the server logs
2023-06-26 09:33:01,911 ERROR middleware.catch-exceptions :: Error processing query: ERROR: canceling statement due to user request
{:database_id 4,
 :started_at #t "2023-06-26T09:23:01.338750Z[GMT]",
 :via
 [{:status :failed,
   :class clojure.lang.ExceptionInfo,
   :error "Error executing query: ERROR: canceling statement due to user request",
   :stacktrace
   ["--> driver.sql_jdbc.execute$execute_reducible_query$fn__71882.invoke(execute.clj:505)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:502)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:489)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:497)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:489)"
    "driver.sql_jdbc$fn__105131.invokeStatic(sql_jdbc.clj:63)"
    "driver.sql_jdbc$fn__105131.invoke(sql_jdbc.clj:61)"
    "query_processor.context$executef.invokeStatic(context.clj:60)"
    "query_processor.context$executef.invoke(context.clj:49)"
    "query_processor.context.default$default_runf.invokeStatic(default.clj:68)"
    "query_processor.context.default$default_runf.invoke(default.clj:66)"
    "query_processor.context$runf.invokeStatic(context.clj:46)"
    "query_processor.context$runf.invoke(context.clj:40)"
    "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:15)"
    "query_processor.reducible$identity_qp.invoke(reducible.clj:12)"
    "query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:197)"
    "query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:182)"
    "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___69266.invoke(cache.clj:223)"
    "query_processor.middleware.permissions$check_query_permissions$fn__64738.invoke(permissions.clj:126)"
    "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__68157.invoke(mbql_to_native.clj:24)"
    "query_processor$fn__70785$combined_post_process__70790$combined_post_process_STAR___70791.invoke(query_processor.clj:243)"
    "query_processor$fn__70785$combined_pre_process__70786$combined_pre_process_STAR___70787.invoke(query_processor.clj:240)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__69177$fn__69182.invoke(resolve_database_and_driver.clj:36)"
    "driver$do_with_driver.invokeStatic(driver.clj:90)"
    "driver$do_with_driver.invoke(driver.clj:86)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__69177.invoke(resolve_database_and_driver.clj:35)"
    "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65048.invoke(fetch_source_query.clj:316)"
    "query_processor.middleware.store$initialize_store$fn__65226$fn__65227.invoke(store.clj:12)"
    "query_processor.store$do_with_store.invokeStatic(store.clj:47)"
    "query_processor.store$do_with_store.invoke(store.clj:41)"
    "query_processor.middleware.store$initialize_store$fn__65226.invoke(store.clj:11)"
    "query_processor.middleware.normalize_query$normalize$fn__69466.invoke(normalize_query.clj:25)"
    "query_processor.middleware.constraints$add_default_userland_constraints$fn__66404.invoke(constraints.clj:54)"
    "query_processor.middleware.process_userland_query$process_userland_query$fn__69402.invoke(process_userland_query.clj:151)"
    "query_processor.middleware.catch_exceptions$catch_exceptions$fn__69779.invoke(catch_exceptions.clj:171)"
    "query_processor.reducible$async_qp$qp_STAR___59547$thunk__59549.invoke(reducible.clj:103)"
    "query_processor.reducible$async_qp$qp_STAR___59547$fn__59551.invoke(reducible.clj:108)"],
   :error_type :invalid-query,
   :ex-data
   {:driver :postgres,
    :sql
    ["-- Metabase:: userID: 1 queryType: native queryHash: 6191f0556c8b40aca00f80cd94730f5fb9ed11310e96cbc3aecd38664f7dd515"
     "query"],
    :params
    [],
    :type :invalid-query}}],
 :state "57014",
 :error_type :invalid-query,
 :json_query
 {:constraints {:max-results 10000, :max-results-bare-rows 2000},
  :type :native,
  :middleware {:js-int-to-string? true, :ignore-cached-results? true, :process-viz-settings? false},
  :native
  {:query
   "",
   :template-tags
   {"uri" {:id "84a87753-457e-95fa-e798-fe7d46ee1f77", :name "uri", :display-name "Uri", :type :text},
    "min_count"
    {:id "f794f9d0-28c0-2a90-c8c8-f5ce1059911c",
     :name "min_count",
     :display-name "Min count",
     :type :text,
     :required true,
     :default "0"},
    "date"
    {:id "db8682fa-c7a6-9aca-818d-9a67481968b6",
     :name "date",
     :display-name "Date",
     :type :text,
     :required true,
     :default "2023-06-21"}}},
  :database 4,
  :parameters
  [],
  :async? true,
  :cache-ttl 180},
 :status :failed,
 :class org.postgresql.util.PSQLException,
 :stacktrace
 ["org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)"
  "org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)"
  "org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)"
  "org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)"
  "org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)"
  "org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)"
  "org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134)"
  "com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:1471)"
  "--> driver.sql_jdbc.execute$fn__71805.invokeStatic(execute.clj:380)"
  "driver.sql_jdbc.execute$fn__71805.invoke(execute.clj:378)"
  "driver.sql_jdbc.execute$execute_statement_or_prepared_statement_BANG_.invokeStatic(execute.clj:393)"
  "driver.sql_jdbc.execute$execute_statement_or_prepared_statement_BANG_.invoke(execute.clj:389)"
  "driver.sql_jdbc.execute$execute_reducible_query$fn__71882.invoke(execute.clj:503)"
  "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:502)"
  "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:489)"
  "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:497)"
  "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:489)"
  "driver.sql_jdbc$fn__105131.invokeStatic(sql_jdbc.clj:63)"
  "driver.sql_jdbc$fn__105131.invoke(sql_jdbc.clj:61)"
  "query_processor.context$executef.invokeStatic(context.clj:60)"
  "query_processor.context$executef.invoke(context.clj:49)"
  "query_processor.context.default$default_runf.invokeStatic(default.clj:68)"
  "query_processor.context.default$default_runf.invoke(default.clj:66)"
  "query_processor.context$runf.invokeStatic(context.clj:46)"
  "query_processor.context$runf.invoke(context.clj:40)"
  "query_processor.reducible$identity_qp.invokeStatic(reducible.clj:15)"
  "query_processor.reducible$identity_qp.invoke(reducible.clj:12)"
  "query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:197)"
  "query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:182)"
  "query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___69266.invoke(cache.clj:223)"
  "query_processor.middleware.permissions$check_query_permissions$fn__64738.invoke(permissions.clj:126)"
  "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__68157.invoke(mbql_to_native.clj:24)"
  "query_processor$fn__70785$combined_post_process__70790$combined_post_process_STAR___70791.invoke(query_processor.clj:243)"
  "query_processor$fn__70785$combined_pre_process__70786$combined_pre_process_STAR___70787.invoke(query_processor.clj:240)"
  "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__69177$fn__69182.invoke(resolve_database_and_driver.clj:36)"
  "driver$do_with_driver.invokeStatic(driver.clj:90)"
  "driver$do_with_driver.invoke(driver.clj:86)"
  "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__69177.invoke(resolve_database_and_driver.clj:35)"
  "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__65048.invoke(fetch_source_query.clj:316)"
  "query_processor.middleware.store$initialize_store$fn__65226$fn__65227.invoke(store.clj:12)"
  "query_processor.store$do_with_store.invokeStatic(store.clj:47)"
  "query_processor.store$do_with_store.invoke(store.clj:41)"
  "query_processor.middleware.store$initialize_store$fn__65226.invoke(store.clj:11)"
  "query_processor.middleware.normalize_query$normalize$fn__69466.invoke(normalize_query.clj:25)"
  "query_processor.middleware.constraints$add_default_userland_constraints$fn__66404.invoke(constraints.clj:54)"
  "query_processor.middleware.process_userland_query$process_userland_query$fn__69402.invoke(process_userland_query.clj:151)"
  "query_processor.middleware.catch_exceptions$catch_exceptions$fn__69779.invoke(catch_exceptions.clj:171)"
  "query_processor.reducible$async_qp$qp_STAR___59547$thunk__59549.invoke(reducible.clj:103)"
  "query_processor.reducible$async_qp$qp_STAR___59547$fn__59551.invoke(reducible.clj:108)"],
 :card_id 171,
 :context :question,
 :error "ERROR: canceling statement due to user request",
 :row_count 0,
 :running_time 0,
 :data {:rows [], :cols []}}

Getting this on the browser

{
"message":"AsyncContext timeout",
"url":"/api/dataset",
"status":"500"
}

is there anything at the postgres level that might be killing the query?

What should I look for? Postgres has a timeout, however that is for connection time.

That should be somewhere in your Postgres config or maybe you have a pgpool or pgbouncer