[0.30.2: DONE] Metabase 0.30 RC: Queries timing out, other issues (AWS ALB HTTP/2 related)

Hi there, I was trying to use 0.29.3, but it didn’t work because we’re using MongoDB and we have null values. I saw that this got fixed in the 0.30 RC, so I started using that.

It worked for a while, but then I ran a few simple queries that timed out.

I’m running the whole thing on a t2.small EC2 instance (1 vCPU, 2 GB RAM), including the database. I’m wondering if that machine doesn’t have enough RAM to run both the DB and the JVM and the metabase jar…

I’m also getting some interesting stack traces (errors / warnings) in my log file.

Error

It looks like this one is about not supporting fields with mongo type Date. Or maybe it’s because some of my fields of type Date are null.

08-07 06:50:20 e[1mERROR sync.utile[0m :: e[31mError generating fingerprint for Field 922 'trialEnds': No implementation of method: :->date of protocol: #'metabase.sync.analyze.fingerprint.fingerprinters/IDateCoercible found for class: clojure.lang.PersistentArrayMap
("sync.analyze.fingerprint.fingerprinters$fn__36669$G__36664__36674.invoke(fingerprinters.clj:147)"
 "sync.analyze.fingerprint.fingerprinters$with_error_handling$fn__36646$fn__36651.invoke(fingerprinters.clj:110)"
 "sync.util$do_with_error_handling.invokeStatic(util.clj:143)"
 "sync.util$do_with_error_handling.invoke(util.clj:138)"
 "sync.analyze.fingerprint.fingerprinters$with_error_handling$fn__36646.invoke(fingerprinters.clj:110)"
 "sync.analyze.fingerprint.fingerprinters$col_wise$fn__36609$fn__36614.invoke(fingerprinters.clj:26)"
 "sync.analyze.fingerprint.fingerprinters$col_wise$fn__36609.invoke(fingerprinters.clj:23)"
 "sync.analyze.fingerprint$fn__40190$fingerprint_table_BANG___40195$fn__40196.invoke(fingerprint.clj:41)"
 "sync.analyze.fingerprint$fn__40190$fingerprint_table_BANG___40195.invoke(fingerprint.clj:39)"
 "sync.analyze.fingerprint$fn__40363$fingerprint_fields_BANG___40368$fn__40369.invoke(fingerprint.clj:160)"
 "sync.analyze.fingerprint$fn__40363$fingerprint_fields_BANG___40368.invoke(fingerprint.clj:156)"
 "sync.analyze.fingerprint$fn__40389$fingerprint_fields_for_db_BANG___40394$fn__40395$fn__40396$iter__40397__40401$fn__40402$fn__40403.invoke(fingerprint.clj:170)"
 "sync.analyze.fingerprint$fn__40389$fingerprint_fields_for_db_BANG___40394$fn__40395$fn__40396$iter__40397__40401$fn__40402.invoke(fingerprint.clj:169)"
 "sync.analyze.fingerprint$fn__40389$fingerprint_fields_for_db_BANG___40394$fn__40395$fn__40396.invoke(fingerprint.clj:169)"
 "util.date$call_with_effective_timezone.invokeStatic(date.clj:82)"
 "util.date$call_with_effective_timezone.invoke(date.clj:71)"
 "sync.analyze.fingerprint$fn__40389$fingerprint_fields_for_db_BANG___40394$fn__40395.invoke(fingerprint.clj:168)"
 "sync.analyze.fingerprint$fn__40389$fingerprint_fields_for_db_BANG___40394.invoke(fingerprint.clj:163)"
 "sync.analyze$make_analyze_steps$fn__40535.invoke(analyze.clj:110)"
 "sync.util$fn__35519$run_step_with_metadata__35524$fn__35528$fn__35530.invoke(util.clj:350)"
 "sync.util$with_start_and_finish_logging_SINGLEQUOTE_.invokeStatic(util.clj:98)"
 "sync.util$with_start_and_finish_logging_SINGLEQUOTE_.invoke(util.clj:92)"
 "sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:115)"
 "sync.util$with_start_and_finish_debug_logging.invoke(util.clj:112)"
 "sync.util$fn__35519$run_step_with_metadata__35524$fn__35528.invoke(util.clj:347)"
 "sync.util$fn__35519$run_step_with_metadata__35524.invoke(util.clj:342)"
 "sync.util$fn__35603$run_sync_operation__35608$fn__35609$fn__35610.invoke(util.clj:397)"
 "sync.util$fn__35603$run_sync_operation__35608$fn__35609.invoke(util.clj:397)"
 "sync.util$fn__35603$run_sync_operation__35608.invoke(util.clj:391)"
 "sync.analyze$fn__40547$analyze_db_BANG___40552$fn__40553$fn__40554.invoke(analyze.clj:127)"
 "sync.util$do_with_error_handling.invokeStatic(util.clj:143)"
 "sync.util$do_with_error_handling.invoke(util.clj:138)"
 "sync.util$do_with_error_handling.invokeStatic(util.clj:141)"
 "sync.util$do_with_error_handling.invoke(util.clj:138)"
 "driver.mongo$sync_in_context$f__58344__auto____59106.invoke(mongo.clj:63)"
 "driver.mongo.util$_with_mongo_connection$fn__58337.invoke(util.clj:115)"
 "util.ssh$with_ssh_tunnel_STAR_.invokeStatic(ssh.clj:106)"
 "util.ssh$with_ssh_tunnel_STAR_.invoke(ssh.clj:91)"
 "driver.mongo.util$_with_mongo_connection.invokeStatic(util.clj:94)"
 "driver.mongo.util$_with_mongo_connection.invoke(util.clj:89)"
 "driver.mongo$sync_in_context.invokeStatic(mongo.clj:62)"
 "driver.mongo$sync_in_context.invoke(mongo.clj:61)"
 "driver$fn__28237$G__28044__28246.invoke(driver.clj:57)"
 "sync.util$sync_in_context$fn__35425.invoke(util.clj:134)"
 "sync.util$with_db_logging_disabled$fn__35422.invoke(util.clj:125)"
 "sync.util$with_start_and_finish_logging_SINGLEQUOTE_.invokeStatic(util.clj:98)"
 "sync.util$with_start_and_finish_logging_SINGLEQUOTE_.invoke(util.clj:92)"
 "sync.util$with_start_and_finish_logging$fn__35411.invoke(util.clj:110)"
 "sync.util$with_sync_events$fn__35406.invoke(util.clj:84)"
 "sync.util$with_duplicate_ops_prevented$fn__35397.invoke(util.clj:63)"
 "sync.util$do_sync_operation.invokeStatic(util.clj:162)"
 "sync.util$do_sync_operation.invoke(util.clj:159)"
 "sync.analyze$fn__40547$analyze_db_BANG___40552$fn__40553.invoke(analyze.clj:124)"
 "sync.analyze$fn__40547$analyze_db_BANG___40552.invoke(analyze.clj:119)"
 "task.sync_databases.SyncAndAnalyzeDatabase.execute(sync_databases.clj:39)")

Warning #1

I’m also getting a warning while making queries, and I’m wondering if that’s why they’re failing / timing out:

08-07 06:38:40 e[1mWARN metabase.query-processore[0m :: e[31m{:status :failed,
 :class java.lang.IllegalArgumentException,
 :error "No implementation of method: :->lvalue of protocol: #'metabase.driver.mongo.query-processor/IField found for class: metabase.query_processor.interface.BinnedField",
 :stacktrace
 ["driver.mongo.query_processor$fn__58555$G__58548__58560.invoke(query_processor.clj:68)"
  "driver.mongo.query_processor$breakouts_and_ags__GT_projected_fields$iter__58685__58689$fn__58690$fn__58691.invoke(query_processor.clj:295)"
  "driver.mongo.query_processor$breakouts_and_ags__GT_projected_fields$iter__58685__58689$fn__58690.invoke(query_processor.clj:294)"
  "driver.mongo.query_processor$handle_breakout_PLUS_aggregation$iter__58750__58754$fn__58755.invoke(query_processor.clj:334)"
  "driver.mongo.query_processor$handle_breakout_PLUS_aggregation.invokeStatic(query_processor.clj:334)"
  "driver.mongo.query_processor$handle_breakout_PLUS_aggregation.invoke(query_processor.clj:323)"
  "driver.mongo.query_processor$generate_aggregation_pipeline$fn__58806.invoke(query_processor.clj:386)"
  "driver.mongo.query_processor$generate_aggregation_pipeline.invokeStatic(query_processor.clj:385)"
  "driver.mongo.query_processor$generate_aggregation_pipeline.invoke(query_processor.clj:382)"
  "driver.mongo.query_processor$mbql__GT_native.invokeStatic(query_processor.clj:512)"
  "driver.mongo.query_processor$mbql__GT_native.invoke(query_processor.clj:506)"
  "driver$fn__28157$G__28052__28164.invoke(driver.clj:57)"
  "query_processor.middleware.mbql_to_native$query__GT_native_form.invokeStatic(mbql_to_native.clj:17)"
  "query_processor.middleware.mbql_to_native$query__GT_native_form.invoke(mbql_to_native.clj:12)"
  "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__32906.invoke(mbql_to_native.clj:26)"
  "query_processor.middleware.annotate_and_sort$annotate_and_sort$fn__31220.invoke(annotate_and_sort.clj:41)"
  "query_processor.middleware.limit$limit$fn__32861.invoke(limit.clj:15)"
  "query_processor.middleware.cumulative_aggregations$cumulative_aggregation$fn__32711.invoke(cumulative_aggregations.clj:58)"
  "query_processor.middleware.cumulative_aggregations$cumulative_aggregation$fn__32711.invoke(cumulative_aggregations.clj:58)"
  "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__36835.invoke(results_metadata.clj:51)"
  "query_processor.middleware.format_rows$format_rows$fn__32851.invoke(format_rows.clj:26)"
  "query_processor.middleware.binning$update_binning_strategy$fn__31314.invoke(binning.clj:165)"
  "query_processor.middleware.resolve$resolve_middleware$fn__30812.invoke(resolve.clj:445)"
  "query_processor.middleware.expand$expand_middleware$fn__32591.invoke(expand.clj:607)"
  "query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__30898.invoke(add_row_count_and_status.clj:15)"
  "driver.mongo$process_query_in_context$fn__59099$f__58344__auto____59101.invoke(mongo.clj:54)"
  "driver.mongo.util$_with_mongo_connection$fn__58337.invoke(util.clj:115)"
  "util.ssh$with_ssh_tunnel_STAR_.invokeStatic(ssh.clj:106)"
  "util.ssh$with_ssh_tunnel_STAR_.invoke(ssh.clj:91)"
  "driver.mongo.util$_with_mongo_connection.invokeStatic(util.clj:94)"
  "driver.mongo.util$_with_mongo_connection.invoke(util.clj:89)"
  "driver.mongo$process_query_in_context$fn__59099.invoke(mongo.clj:53)"
  "query_processor.middleware.driver_specific$process_query_in_context$fn__32731.invoke(driver_specific.clj:12)"
  "query_processor.middleware.resolve_driver$resolve_driver$fn__35378.invoke(resolve_driver.clj:15)"
  "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__31228$fn__31229.invoke(bind_effective_timezone.clj:9)"
  "util.date$call_with_effective_timezone.invokeStatic(date.clj:82)"
  "util.date$call_with_effective_timezone.invoke(date.clj:71)"
  "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__31228.invoke(bind_effective_timezone.clj:8)"
  "query_processor.middleware.cache$maybe_return_cached_results$fn__31403.invoke(cache.clj:149)"
  "query_processor.middleware.catch_exceptions$catch_exceptions$fn__32642.invoke(catch_exceptions.clj:58)"
  "query_processor$process_query.invokeStatic(query_processor.clj:135)"
  "query_processor$process_query.invoke(query_processor.clj:131)"
  "query_processor$run_and_save_query_BANG_.invokeStatic(query_processor.clj:249)"
  "query_processor$run_and_save_query_BANG_.invoke(query_processor.clj:243)"
  "query_processor$fn__36873$process_query_and_save_execution_BANG___36878$fn__36879.invoke(query_processor.clj:289)"
  "query_processor$fn__36873$process_query_and_save_execution_BANG___36878.invoke(query_processor.clj:275)"
  "query_processor$fn__36897$process_query_and_save_with_max_BANG___36902$fn__36903.invoke(query_processor.clj:310)"
  "query_processor$fn__36897$process_query_and_save_with_max_BANG___36902.invoke(query_processor.clj:306)"
  "api.dataset$fn__43331$fn__43334.invoke(dataset.clj:45)"
  "api.common$fn__20617$invoke_thunk_with_keepalive__20622$fn__20623$fn__20624.invoke(common.clj:433)"],
 :query
 {:type "query",
  :query {:source_table 129, :breakout [["binning-strategy" ["field-id" 659] "default"]], :aggregation [["count"]]},
  :parameters [],
  :constraints {:max-results 10000, :max-results-bare-rows 2000},
  :info
  {:executed-by 1,
   :context :ad-hoc,
   :card-id nil,
   :nested? false,
   :query-hash [9, 26, -79, 2, -10, 23, -42, 62, 68, 99, -53, -102, -55, 71, 10, 1, 96, -32, -126, -47, -89, 78, 63, -128, 104, 15, 7, 123, -23, 11, 19, 39],
   :query-type "MBQL"}},
 :expanded-query nil}

Warning #2

Here’s another similar warning:

08-07 06:38:47 e[1mWARN metabase.query-processore[0m :: e[31mQuery failure: No implementation of method: :->lvalue of protocol: #'metabase.driver.mongo.query-processor/IField found for class: metabase.query_processor.interface.BinnedField
["query_processor$assert_query_status_successful.invokeStatic(query_processor.clj:217)"
 "query_processor$assert_query_status_successful.invoke(query_processor.clj:210)"
 "query_processor$run_and_save_query_BANG_.invokeStatic(query_processor.clj:250)"
 "query_processor$run_and_save_query_BANG_.invoke(query_processor.clj:243)"
 "query_processor$fn__36873$process_query_and_save_execution_BANG___36878$fn__36879.invoke(query_processor.clj:289)"
 "query_processor$fn__36873$process_query_and_save_execution_BANG___36878.invoke(query_processor.clj:275)"
 "query_processor$fn__36897$process_query_and_save_with_max_BANG___36902$fn__36903.invoke(query_processor.clj:310)"
 "query_processor$fn__36897$process_query_and_save_with_max_BANG___36902.invoke(query_processor.clj:306)"
 "api.dataset$fn__43331$fn__43334.invoke(dataset.clj:45)"
 "api.common$fn__20617$invoke_thunk_with_keepalive__20622$fn__20623$fn__20624.invoke(common.clj:433)"]

I’m quite new to Metabase, and am not sure where to go from here. Is this a mongo-related RC bug that I should file on GitHub? Appreciate your help in advance!

Quick update: I get those warnings when I try to load an X-ray, and none of my charts load for X-rays.

Also, after trying to load an X-ray and failing, no other query works and I have to ssh into my server and kill the process and re-run it.

I am getting the same issue as well with both 0.30.0 RC and the latest 0.30.0 release. Load any X-ray, and none of charts show up. Then all table queries run forever, even with the Sample Dataset.

Any suggestions?

What’s in the server and javascript console logs?

After the failure x-ray view, any table query will be blocked with “POST /api/dataset” REST API call. I have pasted the detail server debug logs here. The same table query before X-Ray, and after X-Ray.

https://pastebin.com/YLiZPt4V

Just tried with 0.29.3 release as well. I can reproduce the same query lock issue. Pasted server log here for the x-ray operation.

https://pastebin.com/8uAkwYnW

I think it might be related to the database env, and the target database is an instance of RDS PostgreSQL on AWS.

@je2ryw1h are you on Mongo as well?

Nope, the source data is in a read-only replica of PostgreSQL on RDS, and metabase database is also a RDS PostgresSQL. Metabase instance is using the official metabase docker images.

Based on the log pasted here (YLiZPt4V), it seems the query did fetch the data successfully from the target table, just for some reason could not complete the REST response.

My DB connection (to mongo) is also read-only. Probably not related to the issue though.

Is there anything in the JS logs? Do you have access to any server metrics (specifically cpu or memory consumption) of the server post x-ray?

What are you running the docker image on, memory/cpu wise?

On the frontend, it just the usual request (/api/dataset) timeout, and with following error from javascript stack:

api.js:137 POST https://metabase.vdap.ops-ven.com/api/dataset 504 ()
(anonymous) @ api.js:137
_makeRequest @ api.js:106
(anonymous) @ api.js:98
getDatasetQueryResult @ Question.js:461
_callee$ @ app-main.bundle.js?a148caa8cbdb77f1454b:10499
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ Question.js:49
(anonymous) @ Question.js:49
(anonymous) @ Question.js:49
apiGetResults @ app-main.bundle.js?a148caa8cbdb77f1454b:10510
_callee15$ @ actions.js:1199
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:1168
(anonymous) @ store.js:17
dispatch @ applyMiddleware.js:35
(anonymous) @ actions.js:361
setTimeout (async)
_callee2$ @ actions.js:356
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ actions.js:75
(anonymous) @ actions.js:75
Promise.then (async)
step @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:187
(anonymous) @ store.js:17
(anonymous) @ bindActionCreators.js:3
componentWillMount @ QueryBuilder.jsx:147
performInitialMount @ ReactCompositeComponent.js:348
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
performInitialMount @ ReactCompositeComponent.js:368
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
performInitialMount @ ReactCompositeComponent.js:368
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
_updateRenderedComponent @ ReactCompositeComponent.js:762
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
performUpdateIfNecessary @ ReactCompositeComponent.js:558
performUpdateIfNecessary @ ReactReconciler.js:154
runBatchedUpdates @ ReactUpdates.js:148
perform @ Transaction.js:141
perform @ Transaction.js:141
perform @ ReactUpdates.js:87
flushBatchedUpdates @ ReactUpdates.js:170
closeAll @ Transaction.js:207
perform @ Transaction.js:154
batchedUpdates @ ReactDefaultBatchingStrategy.js:60
batchedUpdates @ ReactUpdates.js:95
dispatchEvent @ ReactEventListener.js:145
settings.js:216 Error getting setting table.columns TypeError: Cannot read property ‘cols’ of undefined
at Object.getDefault (Table.jsx:77)
at getSetting (settings.js:207)
at getSettings (settings.js:255)
at app-main.bundle.js?a148caa8cbdb77f1454b:32907
at index.js:76
at index.js:36
at index.js:90
at index.js:36
at Function.mapStateToProps [as mapToProps] (QueryHeader.jsx:43)
at mapToPropsProxy (wrapMapToProps.js:43)
getSetting @ settings.js:216
getSettings @ settings.js:255
(anonymous) @ app-main.bundle.js?a148caa8cbdb77f1454b:32907
(anonymous) @ index.js:76
(anonymous) @ index.js:36
(anonymous) @ index.js:90
(anonymous) @ index.js:36
mapStateToProps @ QueryHeader.jsx:43
mapToPropsProxy @ wrapMapToProps.js:43
handleNewPropsAndNewState @ selectorFactory.js:34
handleSubsequentCalls @ selectorFactory.js:67
pureFinalPropsSelector @ selectorFactory.js:74
runComponentSelector @ connectAdvanced.js:26
componentWillReceiveProps @ connectAdvanced.js:150
updateComponent @ ReactCompositeComponent.js:611
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
performUpdateIfNecessary @ ReactCompositeComponent.js:558
performUpdateIfNecessary @ ReactReconciler.js:154
runBatchedUpdates @ ReactUpdates.js:148
perform @ Transaction.js:141
perform @ Transaction.js:141
perform @ ReactUpdates.js:87
flushBatchedUpdates @ ReactUpdates.js:170
closeAll @ Transaction.js:207
perform @ Transaction.js:154
batchedUpdates @ ReactDefaultBatchingStrategy.js:60
enqueueUpdate @ ReactUpdates.js:198
enqueueUpdate @ ReactUpdateQueue.js:22
enqueueSetState @ ReactUpdateQueue.js:216
ReactComponent.setState @ ReactBaseClasses.js:62
onStateChange @ connectAdvanced.js:205
notify @ Subscription.js:26
notifyNestedSubs @ Subscription.js:65
onStateChange @ connectAdvanced.js:202
dispatch @ createStore.js:173
dispatch @ VM420:1
(anonymous) @ middleware.js:22
(anonymous) @ index.js:28
(anonymous) @ store.js:70
(anonymous) @ store.js:17
dispatch @ applyMiddleware.js:35
_callee$ @ redux.js:16
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ redux.js:13
(anonymous) @ redux.js:13
Promise.then (async)
step @ redux.js:13
(anonymous) @ redux.js:13
(anonymous) @ redux.js:13
(anonymous) @ redux.js:29
(anonymous) @ store.js:17
dispatch @ applyMiddleware.js:35
(anonymous) @ actions.js:1203
Promise.catch (async)
_callee15$ @ actions.js:1203
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:1168
(anonymous) @ store.js:17
dispatch @ applyMiddleware.js:35
(anonymous) @ actions.js:361
setTimeout (async)
_callee2$ @ actions.js:356
tryCatch @ runtime.js:65
invoke @ runtime.js:303
prototype.(anonymous function) @ runtime.js:117
step @ actions.js:75
(anonymous) @ actions.js:75
Promise.then (async)
step @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:75
(anonymous) @ actions.js:187
(anonymous) @ store.js:17
(anonymous) @ bindActionCreators.js:3
componentWillMount @ QueryBuilder.jsx:147
performInitialMount @ ReactCompositeComponent.js:348
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
performInitialMount @ ReactCompositeComponent.js:368
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
performInitialMount @ ReactCompositeComponent.js:368
mountComponent @ ReactCompositeComponent.js:255
mountComponent @ ReactReconciler.js:43
_updateRenderedComponent @ ReactCompositeComponent.js:762
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
updateChildren @ ReactChildReconciler.js:107
_reconcilerUpdateChildren @ ReactMultiChild.js:209
_updateChildren @ ReactMultiChild.js:308
updateChildren @ ReactMultiChild.js:295
_updateDOMChildren @ ReactDOMComponent.js:944
updateComponent @ ReactDOMComponent.js:758
receiveComponent @ ReactDOMComponent.js:720
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
receiveComponent @ ReactCompositeComponent.js:544
receiveComponent @ ReactReconciler.js:122
_updateRenderedComponent @ ReactCompositeComponent.js:751
_performComponentUpdate @ ReactCompositeComponent.js:721
updateComponent @ ReactCompositeComponent.js:642
performUpdateIfNecessary @ ReactCompositeComponent.js:558
performUpdateIfNecessary @ ReactReconciler.js:154
runBatchedUpdates @ ReactUpdates.js:148
perform @ Transaction.js:141
perform @ Transaction.js:141
perform @ ReactUpdates.js:87
flushBatchedUpdates @ ReactUpdates.js:170
closeAll @ Transaction.js:207
perform @ Transaction.js:154
batchedUpdates @ ReactDefaultBatchingStrategy.js:60
batchedUpdates @ ReactUpdates.js:95
dispatchEvent @ ReactEventListener.js:145
ShrinkableList.jsx:44 GET https://metabase.vdap.ops-ven.com/app/app/assets/img/stopwatch.svg 404 ()

The metabase container is running on an AWS t2.medium instance with 2 vCPU and 4G memory. Here is the metabase JVM process from host “top” command, and “free” cmd shows there are still 1.5G physical memory available.

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
9268 2000 20 0 2582m 644m 15m S 0.3 16.3 1:21.72 java

free -m
total used free shared buffers cached
Mem: 3945 2342 1602 0 173 1050
-/+ buffers/cache: 1118 2827
Swap: 0 0 0

@je2ryw you are seeing these freezes when xraying the Sample Database or your own?

Just did several tests, the issue happens on both Sample Database and external RDS PostgreSQL DB. It is kind depend on how many cards generated from the xray. For the example, I can reproduce the freeze with the “Products” table in the Sample Database as well.

Next step, I am planning to build a new docker image with Oracle JVM to see if it is related to the OpenJDK VM or not.

Finally, the query lock down issue with the “POST /api/dataset” has been resolved. It was caused by the “HTTP/2” option enabled on the AWS Application Load Balancer. Once the “HTTP/2” option is disabled, multiple concurrent API requests generated from the X-Ray operation won’t lock the metabase instance anymore.

2 Likes

Good call, @je2ryw. I changed the following setting in CloudFront, and loading X-Rays no longer breaks my instance.

However, several charts are still not loading. I clicked into one of them and got the following:

This matches the warning I show above in my initial post.

The warnings you were getting should be fixed in 0.30 (final).

Still have to get to the bottom of the fingerprinting error.

I’m seeing a similar issue to this. The api/dataset endpoint returns constant 504’s regardless of the query, interestingly enough running a query or previously saved question works fine. Another interesting find is that the output from the Metabase jarfile doesn’t show this endpoint being logged in the debug text like the other endpoints do.

I’ve got Metabase 0.30.0 running on a EC2 t2.medium as well. I’ve got it running behind an Nginx proxy, but I’m also seeing these issues connecting to it directly on port 3000. This Metabase instance is connecting to a MySQL server but the issues are present with the sample dataset as well.

@mmollick I would suggest to do a clean restart with metabase instance on EC2, then only test the X-Ray operations and query operations with port 3000 directly. If it works fine, then make sure your nginx reverse proxy does not have the keep-alive option enabled for the proxy_pass metabase requests. Also set the root logger as DEBUG level in the log4j.properties can help your verify that no jetty connections remain open after requests complete.

1 Like

@je2ryw Thanks for the help. Setting the keepalive_timeout to 0 in the nginx config seems to have cleared it up.

Great to hear, and glad it helps. :facepunch: