search

metabase / metabase

The simplest, fastest way to get business intelligence and analytics to everyone in your company :yum:
https://metabase.com
Other
38.46k stars 5.1k forks source link

Errors in streaming responses return invalid data #13536

Open dpsutton opened 4 years ago

dpsutton commented 4 years ago

Describe the bug Error in https://github.com/metabase/metabase/issues/12761 . Postgres allows for "infinity" datetimetz values which we currently don't handle. Our query processor throws an error when previewing this table and this stacktrace/error is interspersed in the streaming response.

{"data":{"rows":[
["hello","2020-10-20T14:15:47.36747Z"]
{"database_id":225,"started_at":"2020-10-20T14:16:53.465148Z","via":[{"status":"failed","class":"class clojure.lang.ExceptionInfo" ... "constraints":{"max-results":10000,"max-results-bare-rows":2000}},"data":{"rows":[],"cols":[]}}

Note the exception map is well formed but the original structure of data and rows is now just abandoned resulting in an invalid JSON payload

image

Can repro the query (but not with interspersed error/results) with 

(qp/process-query-and-save-with-max-results-constraints!
  {:database 225
   :type :query
   :query {:source-table 292}}
  {:context :ad-hoc})
{:database_id 225,
 :started_at #t "2020-10-20T15:09:30.320238Z[UTC]",
 :via
 [{:status :failed,
   :class clojure.lang.ExceptionInfo,
   :error "Error reducing result rows",
   :stacktrace
   ["--> query_processor.context.default$default_reducef$fn__30460.invoke(default.clj:61)"
    "query_processor.context.default$default_reducef.invokeStatic(default.clj:58)"
    "query_processor.context.default$default_reducef.invoke(default.clj:49)"
    "query_processor.context$reducef.invokeStatic(context.clj:69)"
    "query_processor.context$reducef.invoke(context.clj:62)"
    "query_processor.context.default$default_runf$respond_STAR___30464.invoke(default.clj:70)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:392)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:377)"
    "driver.sql_jdbc$eval63742$fn__63743.invoke(sql_jdbc.clj:49)"
    "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__58569.invoke(mbql_to_native.clj:26)"
    "query_processor.middleware.check_features$check_features$fn__57757.invoke(check_features.clj:42)"
    "query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__58768.invoke(optimize_datetime_filters.clj:133)"
    "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__56453.invoke(auto_parse_filter_values.clj:44)"
    "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__60458.invoke(wrap_value_literals.clj:137)"
    "query_processor.middleware.annotate$add_column_info$fn__56199.invoke(annotate.clj:574)"
    "query_processor.middleware.permissions$check_query_permissions$fn__57616.invoke(permissions.clj:64)"
    "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__59324.invoke(pre_alias_aggregations.clj:40)"
    "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__57846.invoke(cumulative_aggregations.clj:61)"
    "query_processor.middleware.resolve_joins$resolve_joins$fn__59898.invoke(resolve_joins.clj:183)"
    "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__52467.invoke(add_implicit_joins.clj:245)"
    "query_processor.middleware.large_int_id$convert_id_to_string$fn__58514.invoke(large_int_id.clj:44)"
    "query_processor.middleware.limit$limit$fn__58547.invoke(limit.clj:38)"
    "query_processor.middleware.format_rows$format_rows$fn__58486.invoke(format_rows.clj:81)"
    "query_processor.middleware.desugar$desugar$fn__57918.invoke(desugar.clj:22)"
    "query_processor.middleware.binning$update_binning_strategy$fn__56820.invoke(binning.clj:229)"
    "query_processor.middleware.resolve_fields$resolve_fields$fn__57410.invoke(resolve_fields.clj:24)"
    "query_processor.middleware.add_dimension_projections$add_remapping$fn__51992.invoke(add_dimension_projections.clj:318)"
    "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__52215.invoke(add_implicit_clauses.clj:141)"
    "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__52630.invoke(add_source_metadata.clj:105)"
    "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__59549.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"
    "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__56392.invoke(auto_bucket_datetimes.clj:125)"
    "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__57465.invoke(resolve_source_table.clj:46)"
    "query_processor.middleware.parameters$substitute_parameters$fn__59300.invoke(parameters.clj:114)"
    "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__57519.invoke(resolve_referenced.clj:80)"
    "query_processor.middleware.expand_macros$expand_macros$fn__58182.invoke(expand_macros.clj:158)"
    "query_processor.middleware.add_timezone_info$add_timezone_info$fn__52677.invoke(add_timezone_info.clj:15)"
    "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__60290.invoke(splice_params_in_response.clj:32)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__59566$fn__59570.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__59566.invoke(resolve_database_and_driver.clj:27)"
    "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__58408.invoke(fetch_source_query.clj:267)"
    "query_processor.middleware.store$initialize_store$fn__60307$fn__60308.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__60307.invoke(store.clj:10)"
    "query_processor.middleware.cache$maybe_return_cached_results$fn__57362.invoke(cache.clj:209)"
    "query_processor.middleware.validate$validate_query$fn__60324.invoke(validate.clj:10)"
    "query_processor.middleware.normalize_query$normalize$fn__58590.invoke(normalize_query.clj:22)"
    "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__52493.invoke(add_rows_truncated.clj:36)"
    "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__60269.invoke(results_metadata.clj:147)"
    "query_processor.middleware.constraints$add_default_userland_constraints$fn__57781.invoke(constraints.clj:42)"
    "query_processor.middleware.process_userland_query$process_userland_query$fn__59415.invoke(process_userland_query.clj:136)"
    "query_processor.middleware.catch_exceptions$catch_exceptions$fn__57710.invoke(catch_exceptions.clj:174)"
    "query_processor.reducible$async_qp$qp_STAR___51597$thunk__51598.invoke(reducible.clj:101)"
    "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:107)"
    "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:94)"
    "query_processor$base_qp$fn__60467.doInvoke(query_processor.clj:109)"
    "query_processor.reducible$sync_qp$qp_STAR___51606$fn__51607.invoke(reducible.clj:129)"
    "query_processor.reducible$sync_qp$qp_STAR___51606.invoke(reducible.clj:128)"
    "query_processor$process_userland_query.invokeStatic(query_processor.clj:217)"
    "query_processor$process_userland_query.doInvoke(query_processor.clj:213)"
    "query_processor$eval60504$process_query_and_save_execution_BANG___60513$fn__60514.invoke(query_processor.clj:226)"
    "query_processor$eval60504$process_query_and_save_execution_BANG___60513.invoke(query_processor.clj:221)"
    "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557$fn__60558.invoke(query_processor.clj:238)"
    "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557.invoke(query_processor.clj:234)"],
   :error_type :qp,
   :ex-data {:type :qp}}],
 :error_type :qp,
 :json_query
 {:database 225,
  :type :query,
  :query {:source-table 292},
  :middleware {:add-default-userland-constraints? true}},
 :native
 {:query
  "SELECT \"public\".\"demonstrate\".\"stuff\" AS \"stuff\", \"public\".\"demonstrate\".\"t\" AS \"t\" FROM \"public\".\"demonstrate\" LIMIT 2000",
  :params nil},
 :status :failed,
 :class java.time.DateTimeException,
 :stacktrace
 ["java.base/java.time.temporal.ValueRange.checkValidValue(ValueRange.java:311)"
  "java.base/java.time.temporal.ChronoField.checkValidValue(ChronoField.java:717)"
  "java.base/java.time.LocalDate.plusDays(LocalDate.java:1386)"
  "java.base/java.time.LocalDateTime.plusWithOverflow(LocalDateTime.java:1571)"
  "java.base/java.time.LocalDateTime.plusSeconds(LocalDateTime.java:1327)"
  "java.base/java.time.OffsetDateTime.withOffsetSameInstant(OffsetDateTime.java:701)"
  "java_time.zone$eval25758$fn__25763.invoke(zone.clj:343)"
  "java_time.zone$eval25726$fn__25740$G__25717__25747.invoke(zone.clj:317)"
  "--> query_processor.middleware.format_rows$eval58470$fn__58471.invoke(format_rows.clj:56)"
  "query_processor.middleware.format_rows$eval58423$fn__58426$G__58424__58433.invoke(format_rows.clj:12)"
  "query_processor.middleware.format_rows$format_rows_xform$fn__58479$fn__58480.invoke(format_rows.clj:75)"
  "query_processor.middleware.format_rows$format_rows_xform$fn__58479.invoke(format_rows.clj:75)"
  "query_processor.middleware.limit$limit_xform$fn__58544.invoke(limit.clj:25)"
  "query_processor.reducible$reducible_rows$reify__51613.reduce(reducible.clj:157)"
  "query_processor.context.default$default_reducef$fn__30460.invoke(default.clj:59)"
  "query_processor.context.default$default_reducef.invokeStatic(default.clj:58)"
  "query_processor.context.default$default_reducef.invoke(default.clj:49)"
  "query_processor.context$reducef.invokeStatic(context.clj:69)"
  "query_processor.context$reducef.invoke(context.clj:62)"
  "query_processor.context.default$default_runf$respond_STAR___30464.invoke(default.clj:70)"
  "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:392)"
  "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:377)"
  "driver.sql_jdbc$eval63742$fn__63743.invoke(sql_jdbc.clj:49)"
  "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__58569.invoke(mbql_to_native.clj:26)"
  "query_processor.middleware.check_features$check_features$fn__57757.invoke(check_features.clj:42)"
  "query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__58768.invoke(optimize_datetime_filters.clj:133)"
  "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__56453.invoke(auto_parse_filter_values.clj:44)"
  "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__60458.invoke(wrap_value_literals.clj:137)"
  "query_processor.middleware.annotate$add_column_info$fn__56199.invoke(annotate.clj:574)"
  "query_processor.middleware.permissions$check_query_permissions$fn__57616.invoke(permissions.clj:64)"
  "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__59324.invoke(pre_alias_aggregations.clj:40)"
  "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__57846.invoke(cumulative_aggregations.clj:61)"
  "query_processor.middleware.resolve_joins$resolve_joins$fn__59898.invoke(resolve_joins.clj:183)"
  "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__52467.invoke(add_implicit_joins.clj:245)"
  "query_processor.middleware.large_int_id$convert_id_to_string$fn__58514.invoke(large_int_id.clj:44)"
  "query_processor.middleware.limit$limit$fn__58547.invoke(limit.clj:38)"
  "query_processor.middleware.format_rows$format_rows$fn__58486.invoke(format_rows.clj:81)"
  "query_processor.middleware.desugar$desugar$fn__57918.invoke(desugar.clj:22)"
  "query_processor.middleware.binning$update_binning_strategy$fn__56820.invoke(binning.clj:229)"
  "query_processor.middleware.resolve_fields$resolve_fields$fn__57410.invoke(resolve_fields.clj:24)"
  "query_processor.middleware.add_dimension_projections$add_remapping$fn__51992.invoke(add_dimension_projections.clj:318)"
  "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__52215.invoke(add_implicit_clauses.clj:141)"
  "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__52630.invoke(add_source_metadata.clj:105)"
  "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__59549.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"
  "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__56392.invoke(auto_bucket_datetimes.clj:125)"
  "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__57465.invoke(resolve_source_table.clj:46)"
  "query_processor.middleware.parameters$substitute_parameters$fn__59300.invoke(parameters.clj:114)"
  "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__57519.invoke(resolve_referenced.clj:80)"
  "query_processor.middleware.expand_macros$expand_macros$fn__58182.invoke(expand_macros.clj:158)"
  "query_processor.middleware.add_timezone_info$add_timezone_info$fn__52677.invoke(add_timezone_info.clj:15)"
  "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__60290.invoke(splice_params_in_response.clj:32)"
  "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__59566$fn__59570.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__59566.invoke(resolve_database_and_driver.clj:27)"
  "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__58408.invoke(fetch_source_query.clj:267)"
  "query_processor.middleware.store$initialize_store$fn__60307$fn__60308.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__60307.invoke(store.clj:10)"
  "query_processor.middleware.cache$maybe_return_cached_results$fn__57362.invoke(cache.clj:209)"
  "query_processor.middleware.validate$validate_query$fn__60324.invoke(validate.clj:10)"
  "query_processor.middleware.normalize_query$normalize$fn__58590.invoke(normalize_query.clj:22)"
  "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__52493.invoke(add_rows_truncated.clj:36)"
  "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__60269.invoke(results_metadata.clj:147)"
  "query_processor.middleware.constraints$add_default_userland_constraints$fn__57781.invoke(constraints.clj:42)"
  "query_processor.middleware.process_userland_query$process_userland_query$fn__59415.invoke(process_userland_query.clj:136)"
  "query_processor.middleware.catch_exceptions$catch_exceptions$fn__57710.invoke(catch_exceptions.clj:174)"
  "query_processor.reducible$async_qp$qp_STAR___51597$thunk__51598.invoke(reducible.clj:101)"
  "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:107)"
  "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:94)"
  "query_processor$base_qp$fn__60467.doInvoke(query_processor.clj:109)"
  "query_processor.reducible$sync_qp$qp_STAR___51606$fn__51607.invoke(reducible.clj:129)"
  "query_processor.reducible$sync_qp$qp_STAR___51606.invoke(reducible.clj:128)"
  "query_processor$process_userland_query.invokeStatic(query_processor.clj:217)"
  "query_processor$process_userland_query.doInvoke(query_processor.clj:213)"
  "query_processor$eval60504$process_query_and_save_execution_BANG___60513$fn__60514.invoke(query_processor.clj:226)"
  "query_processor$eval60504$process_query_and_save_execution_BANG___60513.invoke(query_processor.clj:221)"
  "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557$fn__60558.invoke(query_processor.clj:238)"
  "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557.invoke(query_processor.clj:234)"],
 :context :ad-hoc,
 :error
 "Invalid value for Year (valid values -999999999 - 999999999): 1000000000",
 :row_count 0,
 :running_time 0,
 :preprocessed
 {:database 225,
  :type :query,
  :query
  {:source-table 292,
   :fields
   [[:field-id 390] [:datetime-field [:field-id 391] :default]],
   :limit 2000},
  :middleware {:add-default-userland-constraints? true},
  :info
  {:context :ad-hoc,
   :query-hash
   [-64, 94, -37, 24, -54, -64, 92, -54, -113, -43, -39, 50, -68,
    -93, 22, 22, 107, 2, -127, 17, 33, 6, -41, 14, 17, -23, 51, -68,
    -85, -45, 33, -14]},
  :constraints {:max-results 10000, :max-results-bare-rows 2000}},
 :data {:rows [], :cols []}}

Logs

10-20 14:53:00 DEBUG middleware.log :: POST /api/dataset 200 2.1 ms (3 DB calls) App DB connections: 0/7 Jetty threads: 5/50 (1 idle, 0 queued) (115 total active threads) Queries in flight: 0 (0 queued)
10-20 14:53:01 ERROR middleware.catch-exceptions :: Error processing query: null
{:database_id 225,
 :started_at #t "2020-10-20T14:53:00.988851Z[UTC]",
 :via
 [{:status :failed,
   :class clojure.lang.ExceptionInfo,
   :error "Error reducing result rows",
   :stacktrace
   ["--> query_processor.context.default$default_reducef$fn__30460.invoke(default.clj:61)"
    "query_processor.context.default$default_reducef.invokeStatic(default.clj:58)"
    "query_processor.context.default$default_reducef.invoke(default.clj:49)"
    "query_processor.context$reducef.invokeStatic(context.clj:69)"
    "query_processor.context$reducef.invoke(context.clj:62)"
    "query_processor.context.default$default_runf$respond_STAR___30464.invoke(default.clj:70)"
    "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:392)"
    "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:377)"
    "driver.sql_jdbc$eval63742$fn__63743.invoke(sql_jdbc.clj:49)"
    "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__58569.invoke(mbql_to_native.clj:26)"
    "query_processor.middleware.check_features$check_features$fn__57757.invoke(check_features.clj:42)"
    "query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__58768.invoke(optimize_datetime_filters.clj:133)"
    "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__56453.invoke(auto_parse_filter_values.clj:44)"
    "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__60458.invoke(wrap_value_literals.clj:137)"
    "query_processor.middleware.annotate$add_column_info$fn__56199.invoke(annotate.clj:574)"
    "query_processor.middleware.permissions$check_query_permissions$fn__57616.invoke(permissions.clj:64)"
    "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__59324.invoke(pre_alias_aggregations.clj:40)"
    "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__57846.invoke(cumulative_aggregations.clj:61)"
    "query_processor.middleware.resolve_joins$resolve_joins$fn__59898.invoke(resolve_joins.clj:183)"
    "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__52467.invoke(add_implicit_joins.clj:245)"
    "query_processor.middleware.large_int_id$convert_id_to_string$fn__58514.invoke(large_int_id.clj:44)"
    "query_processor.middleware.limit$limit$fn__58547.invoke(limit.clj:38)"
    "query_processor.middleware.format_rows$format_rows$fn__58486.invoke(format_rows.clj:81)"
    "query_processor.middleware.desugar$desugar$fn__57918.invoke(desugar.clj:22)"
    "query_processor.middleware.binning$update_binning_strategy$fn__56820.invoke(binning.clj:229)"
    "query_processor.middleware.resolve_fields$resolve_fields$fn__57410.invoke(resolve_fields.clj:24)"
    "query_processor.middleware.add_dimension_projections$add_remapping$fn__51992.invoke(add_dimension_projections.clj:318)"
    "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__52215.invoke(add_implicit_clauses.clj:141)"
    "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__52630.invoke(add_source_metadata.clj:105)"
    "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__59549.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"
    "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__56392.invoke(auto_bucket_datetimes.clj:125)"
    "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__57465.invoke(resolve_source_table.clj:46)"
    "query_processor.middleware.parameters$substitute_parameters$fn__59300.invoke(parameters.clj:114)"
    "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__57519.invoke(resolve_referenced.clj:80)"
    "query_processor.middleware.expand_macros$expand_macros$fn__58182.invoke(expand_macros.clj:158)"
    "query_processor.middleware.add_timezone_info$add_timezone_info$fn__52677.invoke(add_timezone_info.clj:15)"
    "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__60290.invoke(splice_params_in_response.clj:32)"
    "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__59566$fn__59570.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__59566.invoke(resolve_database_and_driver.clj:27)"
    "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__58408.invoke(fetch_source_query.clj:267)"
    "query_processor.middleware.store$initialize_store$fn__60307$fn__60308.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__60307.invoke(store.clj:10)"
    "query_processor.middleware.cache$maybe_return_cached_results$fn__57362.invoke(cache.clj:209)"
    "query_processor.middleware.validate$validate_query$fn__60324.invoke(validate.clj:10)"
    "query_processor.middleware.normalize_query$normalize$fn__58590.invoke(normalize_query.clj:22)"
    "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__52493.invoke(add_rows_truncated.clj:36)"
    "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__60269.invoke(results_metadata.clj:147)"
    "query_processor.middleware.constraints$add_default_userland_constraints$fn__57781.invoke(constraints.clj:42)"
    "query_processor.middleware.process_userland_query$process_userland_query$fn__59415.invoke(process_userland_query.clj:136)"
    "query_processor.middleware.catch_exceptions$catch_exceptions$fn__57710.invoke(catch_exceptions.clj:174)"
    "query_processor.reducible$async_qp$qp_STAR___51597$thunk__51598.invoke(reducible.clj:101)"
    "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:107)"
    "query_processor$base_qp$fn__60467.doInvoke(query_processor.clj:109)"
    "query_processor.reducible$sync_qp$qp_STAR___51606$fn__51609.invoke(reducible.clj:133)"
    "query_processor.reducible$sync_qp$qp_STAR___51606.invoke(reducible.clj:132)"
    "query_processor$process_userland_query.invokeStatic(query_processor.clj:217)"
    "query_processor$process_userland_query.doInvoke(query_processor.clj:213)"
    "query_processor$eval60504$process_query_and_save_execution_BANG___60513$fn__60516.invoke(query_processor.clj:229)"
    "query_processor$eval60504$process_query_and_save_execution_BANG___60513.invoke(query_processor.clj:221)"
    "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557$fn__60560.invoke(query_processor.clj:241)"
    "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557.invoke(query_processor.clj:234)"
    "api.dataset$fn__70287$fn__70290.invoke(dataset.clj:55)"
    "query_processor.streaming$streaming_response_STAR_$fn__102573$fn__102574.invoke(streaming.clj:73)"
    "query_processor.streaming$streaming_response_STAR_$fn__102573.invoke(streaming.clj:72)"
    "async.streaming_response$do_f_STAR_.invokeStatic(streaming_response.clj:66)"
    "async.streaming_response$do_f_STAR_.invoke(streaming_response.clj:64)"
    "async.streaming_response$do_f_async$fn__102868.invoke(streaming_response.clj:85)"],
   :error_type :qp,
   :ex-data {:type :qp}}],
 :error_type :qp,
 :json_query {:database 225, :query {:source-table 292}, :type "query", :parameters [], :middleware {:js-int-to-string? true, :add-default-userland-constraints? true}},
 :native {:query "SELECT \"public\".\"demonstrate\".\"stuff\" AS \"stuff\", \"public\".\"demonstrate\".\"t\" AS \"t\" FROM \"public\".\"demonstrate\" LIMIT 2000", :params nil},
 :status :failed,
 :class java.time.DateTimeException,
 :stacktrace
 ["java.base/java.time.temporal.ValueRange.checkValidValue(ValueRange.java:311)"
  "java.base/java.time.temporal.ChronoField.checkValidValue(ChronoField.java:717)"
  "java.base/java.time.LocalDate.plusDays(LocalDate.java:1386)"
  "java.base/java.time.LocalDateTime.plusWithOverflow(LocalDateTime.java:1571)"
  "java.base/java.time.LocalDateTime.plusSeconds(LocalDateTime.java:1327)"
  "java.base/java.time.OffsetDateTime.withOffsetSameInstant(OffsetDateTime.java:701)"
  "java_time.zone$eval25758$fn__25763.invoke(zone.clj:343)"
  "java_time.zone$eval25726$fn__25740$G__25717__25747.invoke(zone.clj:317)"
  "--> query_processor.middleware.format_rows$eval58470$fn__58471.invoke(format_rows.clj:56)"
  "query_processor.middleware.format_rows$eval58423$fn__58426$G__58424__58433.invoke(format_rows.clj:12)"
  "query_processor.middleware.format_rows$format_rows_xform$fn__58479$fn__58480.invoke(format_rows.clj:75)"
  "query_processor.middleware.format_rows$format_rows_xform$fn__58479.invoke(format_rows.clj:75)"
  "query_processor.middleware.limit$limit_xform$fn__58544.invoke(limit.clj:25)"
  "query_processor.reducible$reducible_rows$reify__51613.reduce(reducible.clj:157)"
  "query_processor.context.default$default_reducef$fn__30460.invoke(default.clj:59)"
  "query_processor.context.default$default_reducef.invokeStatic(default.clj:58)"
  "query_processor.context.default$default_reducef.invoke(default.clj:49)"
  "query_processor.context$reducef.invokeStatic(context.clj:69)"
  "query_processor.context$reducef.invoke(context.clj:62)"
  "query_processor.context.default$default_runf$respond_STAR___30464.invoke(default.clj:70)"
  "driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:392)"
  "driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:377)"
  "driver.sql_jdbc$eval63742$fn__63743.invoke(sql_jdbc.clj:49)"
  "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__58569.invoke(mbql_to_native.clj:26)"
  "query_processor.middleware.check_features$check_features$fn__57757.invoke(check_features.clj:42)"
  "query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__58768.invoke(optimize_datetime_filters.clj:133)"
  "query_processor.middleware.auto_parse_filter_values$auto_parse_filter_values$fn__56453.invoke(auto_parse_filter_values.clj:44)"
  "query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__60458.invoke(wrap_value_literals.clj:137)"
  "query_processor.middleware.annotate$add_column_info$fn__56199.invoke(annotate.clj:574)"
  "query_processor.middleware.permissions$check_query_permissions$fn__57616.invoke(permissions.clj:64)"
  "query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__59324.invoke(pre_alias_aggregations.clj:40)"
  "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__57846.invoke(cumulative_aggregations.clj:61)"
  "query_processor.middleware.resolve_joins$resolve_joins$fn__59898.invoke(resolve_joins.clj:183)"
  "query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__52467.invoke(add_implicit_joins.clj:245)"
  "query_processor.middleware.large_int_id$convert_id_to_string$fn__58514.invoke(large_int_id.clj:44)"
  "query_processor.middleware.limit$limit$fn__58547.invoke(limit.clj:38)"
  "query_processor.middleware.format_rows$format_rows$fn__58486.invoke(format_rows.clj:81)"
  "query_processor.middleware.desugar$desugar$fn__57918.invoke(desugar.clj:22)"
  "query_processor.middleware.binning$update_binning_strategy$fn__56820.invoke(binning.clj:229)"
  "query_processor.middleware.resolve_fields$resolve_fields$fn__57410.invoke(resolve_fields.clj:24)"
  "query_processor.middleware.add_dimension_projections$add_remapping$fn__51992.invoke(add_dimension_projections.clj:318)"
  "query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__52215.invoke(add_implicit_clauses.clj:141)"
  "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__52630.invoke(add_source_metadata.clj:105)"
  "query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__59549.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"
  "query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__56392.invoke(auto_bucket_datetimes.clj:125)"
  "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__57465.invoke(resolve_source_table.clj:46)"
  "query_processor.middleware.parameters$substitute_parameters$fn__59300.invoke(parameters.clj:114)"
  "query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__57519.invoke(resolve_referenced.clj:80)"
  "query_processor.middleware.expand_macros$expand_macros$fn__58182.invoke(expand_macros.clj:158)"
  "query_processor.middleware.add_timezone_info$add_timezone_info$fn__52677.invoke(add_timezone_info.clj:15)"
  "query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__60290.invoke(splice_params_in_response.clj:32)"
  "query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__59566$fn__59570.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__59566.invoke(resolve_database_and_driver.clj:27)"
  "query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__58408.invoke(fetch_source_query.clj:267)"
  "query_processor.middleware.store$initialize_store$fn__60307$fn__60308.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__60307.invoke(store.clj:10)"
  "query_processor.middleware.cache$maybe_return_cached_results$fn__57362.invoke(cache.clj:209)"
  "query_processor.middleware.validate$validate_query$fn__60324.invoke(validate.clj:10)"
  "query_processor.middleware.normalize_query$normalize$fn__58590.invoke(normalize_query.clj:22)"
  "query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__52493.invoke(add_rows_truncated.clj:36)"
  "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__60269.invoke(results_metadata.clj:147)"
  "query_processor.middleware.constraints$add_default_userland_constraints$fn__57781.invoke(constraints.clj:42)"
  "query_processor.middleware.process_userland_query$process_userland_query$fn__59415.invoke(process_userland_query.clj:136)"
  "query_processor.middleware.catch_exceptions$catch_exceptions$fn__57710.invoke(catch_exceptions.clj:174)"
  "query_processor.reducible$async_qp$qp_STAR___51597$thunk__51598.invoke(reducible.clj:101)"
  "query_processor.reducible$async_qp$qp_STAR___51597.invoke(reducible.clj:107)"
  "query_processor$base_qp$fn__60467.doInvoke(query_processor.clj:109)"
  "query_processor.reducible$sync_qp$qp_STAR___51606$fn__51609.invoke(reducible.clj:133)"
  "query_processor.reducible$sync_qp$qp_STAR___51606.invoke(reducible.clj:132)"
  "query_processor$process_userland_query.invokeStatic(query_processor.clj:217)"
  "query_processor$process_userland_query.doInvoke(query_processor.clj:213)"
  "query_processor$eval60504$process_query_and_save_execution_BANG___60513$fn__60516.invoke(query_processor.clj:229)"
  "query_processor$eval60504$process_query_and_save_execution_BANG___60513.invoke(query_processor.clj:221)"
  "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557$fn__60560.invoke(query_processor.clj:241)"
  "query_processor$eval60548$process_query_and_save_with_max_results_constraints_BANG___60557.invoke(query_processor.clj:234)"
  "api.dataset$fn__70287$fn__70290.invoke(dataset.clj:55)"
  "query_processor.streaming$streaming_response_STAR_$fn__102573$fn__102574.invoke(streaming.clj:73)"
  "query_processor.streaming$streaming_response_STAR_$fn__102573.invoke(streaming.clj:72)"
  "async.streaming_response$do_f_STAR_.invokeStatic(streaming_response.clj:66)"
  "async.streaming_response$do_f_STAR_.invoke(streaming_response.clj:64)"
  "async.streaming_response$do_f_async$fn__102868.invoke(streaming_response.clj:85)"],
 :context :ad-hoc,
 :error "Invalid value for Year (valid values -999999999 - 999999999): 1000000000",
 :row_count 0,
 :running_time 0,
 :preprocessed
 {:database 225,
  :query {:source-table 292, :fields [[:field-id 390] [:datetime-field [:field-id 391] :default]], :limit 2000},
  :type :query,
  :middleware {:js-int-to-string? true, :add-default-userland-constraints? true},
  :info
  {:executed-by 1,
   :context :ad-hoc,
   :nested? false,
   :query-hash [-64, 94, -37, 24, -54, -64, 92, -54, -113, -43, -39, 50, -68, -93, 22, 22, 107, 2, -127, 17, 33, 6, -41, 14, 17, -23, 51, -68, -85, -45, 33, -14]},
  :constraints {:max-results 10000, :max-results-bare-rows 2000}},
 :data {:rows [], :cols []}}

Note the underlying bug here is being worked on in the linked ticket. This bug report is about error handling in the streaming query response NOT the instant error here.

To Reproduce If the infinity timestamptz bug is not fixed or you can back out that patch,

create table demonstrate (stuff text, t timestamptz);
insert into demonstrate (stuff, t) values ('hello', now()), ('infinity', 'infinity');

sync your database then click on the demonstrate table and you should get this malformed JSON response.

Expected behavior I'm honestly not sure. A couple possibilities:

  1. return an empty row and keep going, possibly having a mutable context that can accumulate distinct errors and stream them back, with the UI now aware that some rows are omitted due to errors
  2. close the results vector and add the error into the same JSON response
  3. not sure if we have an open websocket but perhaps on an alternative channel send the error information and just swallow errors in the qp

Severity The error handling seems to be decent here. The UI just shows

image

Which is a decent response to something going wrong. Its just a bit off that we are generating invalid JSON.

flamber commented 4 years ago

@dpsutton Looks like it's definitely friends with #12586 and possibly #12600

dpsutton commented 4 years ago

Yeah it looks like those are all instances of this fundamental bug: we intersperse results JSON with error JSON and its not a coherent mix.

WiNloSt commented 1 year ago

While trying to repro https://github.com/metabase/metabase/issues/12586, which pointed out that we could use this issue to repro that one too, I found that I couldn't reproduce the error anymore.

I'm using master @ e55e7f78c74526472e8b5aa4996a45e9157cb445

Result from clicking on the table

image

Result from Postgres

image

Though the timestamp display is definitely weird, it won't crash the question like when it was reported

image