Error after migrating to 0.30.1

[cdaguerre]

Hi,

After upgrading from 0.28 oto 0.30.1, we have this error in our logs and metabase seems to freeze.
I tried to identify the question (card?) raising the issue but can't seem to identify the problem.

Sep 04 13:40:16 ERROR metabase.query-processor.middleware.results-metadata :: Error recording results metadata for query: Output of stored-column-metadata->result-column-metadata does not match schema: 

 {:name (not ("Non-blank string" " "))} 


["sync.analyze.query_results$fn__36868$stored_column_metadata__GT_result_column_metadata__36873.invoke(query_results.clj:48)"
"sync.analyze.query_results$fn__36891$results__GT_column_metadata__36896$fn__36897$iter__36898__36902$fn__36903$fn__36904.invoke(query_results.clj:66)"
"sync.analyze.query_results$fn__36891$results__GT_column_metadata__36896$fn__36897$iter__36898__36902$fn__36903.invoke(query_results.clj:63)"
"sync.analyze.query_results$fn__36891$results__GT_column_metadata__36896$fn__36897$iter__36911__36915$fn__36916.invoke(query_results.clj:69)"
"sync.analyze.query_results$fn__36891$results__GT_column_metadata__36896$fn__36897.invoke(query_results.clj:69)"
"sync.analyze.query_results$fn__36891$results__GT_column_metadata__36896.invoke(query_results.clj:60)"
"query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__36951.invoke(results_metadata.clj:55)"
"query_processor.middleware.format_rows$format_rows$fn__32967.invoke(format_rows.clj:26)"
"query_processor.middleware.binning$update_binning_strategy$fn__31430.invoke(binning.clj:165)"
"query_processor.middleware.resolve$resolve_middleware$fn__30924.invoke(resolve.clj:483)"
"query_processor.middleware.expand$expand_middleware$fn__32707.invoke(expand.clj:607)"
"query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__31010.invoke(add_row_count_and_status.clj:15)"
"query_processor.middleware.driver_specific$process_query_in_context$fn__32847.invoke(driver_specific.clj:12)"
"query_processor.middleware.resolve_driver$resolve_driver$fn__35494.invoke(resolve_driver.clj:15)"
"query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__31344$fn__31345.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__31344.invoke(bind_effective_timezone.clj:8)"
"query_processor.middleware.cache$run_query_and_save_results_if_successful_BANG_.invokeStatic(cache.clj:116)"
"query_processor.middleware.cache$run_query_and_save_results_if_successful_BANG_.invoke(cache.clj:114)"
"query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:127)"
"query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:124)"
"query_processor.middleware.cache$maybe_return_cached_results$fn__31519.invoke(cache.clj:150)"
"query_processor.middleware.catch_exceptions$catch_exceptions$fn__32758.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__36989$process_query_and_save_execution_BANG___36994$fn__36995.invoke(query_processor.clj:289)"
"query_processor$fn__36989$process_query_and_save_execution_BANG___36994.invoke(query_processor.clj:275)"
"api.card$run_query_for_card.invokeStatic(card.clj:582)"
"api.card$run_query_for_card.doInvoke(card.clj:568)"
"api.card$fn__46200$fn__46203.invoke(card.clj:589)"
"api.card$fn__46200.invokeStatic(card.clj:588)"
"api.card$fn__46200.invoke(card.clj:584)"
"middleware$enforce_authentication$fn__55250.invoke(middleware.clj:116)"
"api.routes$fn__55390.invokeStatic(routes.clj:61)"
"api.routes$fn__55390.invoke(routes.clj:61)"
"routes$fn__55477$fn__55478.doInvoke(routes.clj:108)"
"routes$fn__55477.invokeStatic(routes.clj:103)"
"routes$fn__55477.invoke(routes.clj:103)"
"middleware$catch_api_exceptions$fn__55379.invoke(middleware.clj:424)"
"middleware$log_api_call$fn__55356$fn__55358.invoke(middleware.clj:351)"
"middleware$log_api_call$fn__55356.invoke(middleware.clj:350)"
"middleware$add_security_headers$fn__55304.invoke(middleware.clj:253)"
"core$wrap_streamed_json_response$fn__60666.invoke(core.clj:67)"
"middleware$bind_current_user$fn__55255.invoke(middleware.clj:140)"
"middleware$maybe_set_site_url$fn__55308.invoke(middleware.clj:277)"]

We are running metabase on kubernetes in GCP.
MySQL is used as metabase storage and the metabase instance is connected to two MySQL databases.
We use MySQL views in several questions...

[jornh]

The error you’re seeing in the logs may or may not be related to the freezing.

One issue where several people have seen freezes have been identified and the fix for that just got merged to master and will be part of an upcoming 0.30.2 bugfix release is talked about in this post and onwards: #8312 (comment)

For that bug to apply to your environment you should be running https behind a proxy (e.g. nginx on Kube?) that possibly also is configured for HTTP/2.

[sbelak]

@cdaguerre while I have a fix ready in #8453 I'm a bit weirded about some of the specifics of the error you hit, namely it implies you are getting back a column named " " (ie. blank string, but with a space). What kind of query/question is that? Ideally could you share how does the field data.cols in response from POST /api/dataset for this question look like.

[jornh]

With #8312 resolved in 0.30.2 I’m wondering if your freezing got squashed as well?

Please retest with 0.30.2 just out, which should also include #8474. Thanks! 🙂

[salsakran]

@cdaguerre did this get resolved with 0.30.2 (or later?)

[cdaguerre]

@salsakran I think so! Closing this issue....