How Can i Change the Bigquery query execution timeout in metabase

Hello Guys,

I was facing “your question takes too long to execute” issue in Metabase 0.35.4 while executing query in one of the Bigquery Dataset. We hosted Metabase on GCP GKE, so I have increased LB timeout from 30sec to 3600 sec and now the query is able to execute up to 4 mins and after 4 mins it displays query timed out issue again,

is there any place we should increase the timeout in Metabase configurations?
We have queries that execute in Bigquery for more than 15 mins, so was trying to find out more logs, but it just displays timed out all the time.

Is anyone come across the same issue using Metabase while connecting to Bigquery?

Thanks

Hi @sandeepgaridepalli
Have a look in the logs - Admin > Troubleshooting > Logs - it will tell you what part of the connection was closed.
https://www.metabase.com/docs/latest/troubleshooting-guide/proxies.html

1 Like

Hello @sandeepgaridepalli,
You can split the big query, in case that it the same query use many joins you can split in views and then join in another view main with the views that was splited.
With this you distribute the charger from big query in little operations and in the final the main view go to do the work better well.

I solved a problem looks like with your with my big query that it is show timeout using this one logic.

Best regards,

1 Like

Hi @flamber ,

Thanks for your reply.

This is what i get in logs even after increasing the timeout of a HTTPS LB in GCP GKE, there isn’t any proxy timeout set. we use target proxy here, only backend service has timeout which we used in HTTPS LB.

but logs are not giving the correct info, which connection is disconnecting after 4mins.

same query works fine in bigquery.

[f08970b5-5c51-4c48-8dc7-b728642449fa] 2020-07-12T21:19:20+05:30 ERROR metabase.query-processor.middleware.catch-exceptions Error processing query: null
{:database_id 7,
:started_at (t/zoned-date-time “2020-07-12T15:45:20.231892Z[GMT]”),
:json_query
{:constraints {:max-results 10000, :max-results-bare-rows 2000},
:type :native,
:middleware nil,
:native
{:query
“with joiin as (\nSELECT ARRAY_REVERSE(split(table_id,’’))[safe_offset(0)] dt, ‘Joined’ Jn_Table, sum(row_count) r_cnt FROM newscorp-newsiq.newsiq_dfp.dfp_metadata_lookup \nwhere table_id like ‘%reg_joined%’ --and table_id not like ‘%reg%’ and table_id not like ‘%bkp%’\nand PARSE_DATE (’%Y%m%d’,ARRAY_REVERSE(split(table_id,’’))[safe_offset(0)]) BETWEEN DATE_ADD (CURRENT_DATE(), INTERVAL -30 DAY) AND CURRENT_DATE()\ngroup by 1\n),\nbf as (\nSELECT TABLE_SUFFIX as dt, count(distinct(concat(key_part, time_usec2))) prod_cnt FROM newscorp-newsiq.newsiq_ad_value.non_backfill_*\nWHERE PARSE_DATE (’%Y%m%d’, TABLE_SUFFIX) BETWEEN DATE_ADD (CURRENT_DATE(), INTERVAL -30 DAY) AND CURRENT_DATE()\ngroup by 1\n)\nselect a.dt, r_cnt joined_count, prod_cnt product_count\nfrom joiin as a\ninner join \nbf as c on a.dt = c.dt\norder by dt desc",
:template-tags {}},
:database 7,
:parameters [],
:async? true,
:cache-ttl 2401},
:status :failed,
:class clojure.lang.ExceptionInfo,
:stacktrace
["–> driver.bigquery$do_with_finished_response.invokeStatic(bigquery.clj:149)"
“driver.bigquery$do_with_finished_response.invoke(bigquery.clj:132)”
“driver.bigquery$post_process_native.invokeStatic(bigquery.clj:166)”
“driver.bigquery$post_process_native.invoke(bigquery.clj:163)”
"driver.bigquery$process_native_STAR
$thunk__1474.invoke(bigquery.clj:212)"
"driver.bigquery$process_native_STAR
.invokeStatic(bigquery.clj:217)”
“driver.bigquery$process_native_STAR_.invoke(bigquery.clj:207)”
“driver.bigquery$eval1478$fn__1480.invoke(bigquery.clj:231)”
“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:69)”
“query_processor.context.default$default_runf.invoke(default.clj:67)”
“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__43149.invoke(mbql_to_native.clj:26)”
“query_processor.middleware.check_features$check_features$fn__42463.invoke(check_features.clj:42)”
“query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__43314.invoke(optimize_datetime_filters.clj:133)”
“query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__47282.invoke(wrap_value_literals.clj:137)”
“query_processor.middleware.annotate$add_column_info$fn__41084.invoke(annotate.clj:577)”
“query_processor.middleware.permissions$check_query_permissions$fn__42338.invoke(permissions.clj:64)”
“query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__43813.invoke(pre_alias_aggregations.clj:40)”
“query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__42536.invoke(cumulative_aggregations.clj:61)”
“query_processor.middleware.resolve_joins$resolve_joins$fn__44345.invoke(resolve_joins.clj:183)”
“query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__39271.invoke(add_implicit_joins.clj:245)”
“query_processor.middleware.limit$limit$fn__43135.invoke(limit.clj:38)”
“query_processor.middleware.format_rows$format_rows$fn__43116.invoke(format_rows.clj:81)”
“query_processor.middleware.desugar$desugar$fn__42602.invoke(desugar.clj:22)”
“query_processor.middleware.binning$update_binning_strategy$fn__41628.invoke(binning.clj:229)”
“query_processor.middleware.resolve_fields$resolve_fields$fn__42144.invoke(resolve_fields.clj:24)”
“query_processor.middleware.add_dimension_projections$add_remapping$fn__38807.invoke(add_dimension_projections.clj:270)”
“query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__39027.invoke(add_implicit_clauses.clj:147)”
“query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__39420.invoke(add_source_metadata.clj:105)”
“query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__44010.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)”
“query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__41269.invoke(auto_bucket_datetimes.clj:125)”
“query_processor.middleware.resolve_source_table$resolve_source_tables$fn__42191.invoke(resolve_source_table.clj:46)”
“query_processor.middleware.parameters$substitute_parameters$fn__43795.invoke(parameters.clj:97)”
“query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__42243.invoke(resolve_referenced.clj:80)”
“query_processor.middleware.expand_macros$expand_macros$fn__42858.invoke(expand_macros.clj:158)”
“query_processor.middleware.add_timezone_info$add_timezone_info$fn__39451.invoke(add_timezone_info.clj:15)”
“query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__47166.invoke(splice_params_in_response.clj:32)”
“query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__44021$fn__44025.invoke(resolve_database_and_driver.clj:33)”
“driver$do_with_driver.invokeStatic(driver.clj:61)”
“driver$do_with_driver.invoke(driver.clj:57)”
“query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__44021.invoke(resolve_database_and_driver.clj:27)”
“query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__43064.invoke(fetch_source_query.clj:243)”
“query_processor.middleware.store$initialize_store$fn__47175$fn__47176.invoke(store.clj:11)”
“query_processor.store$do_with_store.invokeStatic(store.clj:46)”
“query_processor.store$do_with_store.invoke(store.clj:40)”
“query_processor.middleware.store$initialize_store$fn__47175.invoke(store.clj:10)”
“query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:182)”
“query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:173)”
“query_processor.middleware.cache$maybe_return_cached_results$fn__42120.invoke(cache.clj:208)”
“query_processor.middleware.validate$validate_query$fn__47184.invoke(validate.clj:10)”
“query_processor.middleware.normalize_query$normalize$fn__43162.invoke(normalize_query.clj:22)”
“query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__39289.invoke(add_rows_truncated.clj:36)”
“query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__47151.invoke(results_metadata.clj:128)”
“query_processor.middleware.constraints$add_default_userland_constraints$fn__42479.invoke(constraints.clj:42)”
“query_processor.middleware.process_userland_query$process_userland_query$fn__43884.invoke(process_userland_query.clj:136)”
“query_processor.middleware.catch_exceptions$catch_exceptions$fn__42422.invoke(catch_exceptions.clj:174)”
“query_processor.reducible$async_qp$qp_STAR___38090$thunk__38091.invoke(reducible.clj:101)”
“query_processor.reducible$async_qp$qp_STAR___38090$fn__38093.invoke(reducible.clj:106)”],
:context :question,
:error “Query timed out.”,
:row_count 0,
:running_time 0,
:ex-data {“jobComplete” false, “jobReference” {“jobId” “job_d2RxwPNbGO8CUYNO72tWduSK8JVF”, “location” “US”, “projectId” “newscorp-newsiq”}, “kind” “bigquery#queryResponse”},
:data {:rows [], :cols []}}

[f08970b5-5c51-4c48-8dc7-b728642449fa] 2020-07-12T21:19:20+05:30 DEBUG metabase.middleware.log POST /api/card/257/query 202 [ASYNC: completed] 4.0 mins (6 DB calls) App DB connections: 0/4 Jetty threads: 6/50 (2 idle, 0 queued) (49 total active threads) Queries in flight: 0 (0 queued)
[ac05cbce-78b4-420b-b2ae-0cf287c3f1c4] 2020-07-12T21:19:26+05:30 DEBUG metabase.middleware.log GET /api/setting 200 2.8 ms (0 DB calls) App DB connections: 0/4 Jetty threads: 7/50 (1 idle, 0 queued) (42 total active threads) Queries in flight: 0 (0 queued)
[f08970b5-5c51-4c48-8dc7-b728642449fa] 2020-07-12T21:19:26+05:30 DEBUG metabase.middleware.log GET /api/session/properties 200 15.6 ms (2 DB calls) App DB connections: 0/4 Jetty threads: 7/50 (2 idle, 0 queued) (49 total active threads) Queries in flight: 0 (0 queued)

Thanks

@sandeepgaridepalli I have a feeling that you might be seeing something related to this:
https://github.com/metabase/metabase/issues/12003
No quite sure why it’s timing out after 240 seconds.

Hi @sandeepgaridepalli could you please test the query in your tools manager database?
With this we can detect if the issue it is metabase or in optimization from query.

Best regards,

1 Like

Hi @edimar Yes I am able to execute the same query in Bigquery UI, it ran for 13 mins 41sec processed 946GB data.

Same query is giving timed out issue in Metabase.

tried multiple queries in Metabase without innerjoins.

Regards
G. Sandeep Kumar

@sandeepgaridepalli, In my opinion your big query need to split because for me, the time in another tool it is very long time.

I think that you need to split to request better perform.

Best Regards,

@flamber by using this info (https://github.com/metabase/metabase/issues/12003), I was able to modify the Bigquery module timeout to 60,000.
Now the query is able to execute up to 10 mins. but after 10 mins Metabase is giving “Your question took too long” we did not get an answer from your database" issue, looks like a connection timeout.

I was trying to modify below timeouts to increase the connection timeout in bigquery.clj file in bigquery module, but even if i change the below values it is not affecting, metabase is still giving the same issue again (Your question took too long")
(.setConnectTimeout httpRequest 0)
(.setReadTimeout httpRequest 0))))

@edimar @flamber Is there any place where I can increase the Database connection timeouts in Metabase?

@sandeepgaridepalli But what is closing the connection? Please post the full error from Admin > Troubleshooting > Logs.

Hi @sandeepgaridepalli and @flamber in this case I guess that need adjust the time in both enviroment Metabase = 240,000 and MySQL = 240,000 for example. The Matabase canot be more than the Database.

Try the suggest from @flamber, therefore is very important verify this one approach above.

Best regards,