Non-specific Failure on Simple Question

Hi—we have just migrated some new data to a Presto cluster hosted on AWS EMR. During testing, we are receiving a generic “There was a problem with your question”. Because their is an overlay on the screen, I’m not directly able to click “Show error details”, but with a little hacking, I see that the error message is

Minified React error #31; visit http://facebook.github.io/react/docs/error-decoder.html?invariant=31&args[]=object%20with%20keys%20%7Ben%7D&args[]= for the full message or use the non-minified dev environment for full errors and additional helpful warnings.

I’ve take a picture of the Chrome console which I’ve attached to this post.

When I try to view the logs under Admin > Troubleshooting > Logs, the page freezes and Chrome wants to kill the page. I do the query successfully running on the Presto server.

Here is query generated, pulled from the Presto server directly:

-- Metabase:: userID: 4 queryType: MBQL queryHash: 445c3ddde67d27e7017256240fa7b78beac3e28cb66d79c01c0b54f2a765c293
SELECT "dbt_confidential_murmur"."responses"."_id" AS "_id", "dbt_confidential_murmur"."responses"."created_at" AS "created_at", "dbt_confidential_murmur"."responses"."demonstration" AS "demonstration", "dbt_confidential_murmur"."responses"."expired_at" AS "expired_at", "dbt_confidential_murmur"."responses"."murmur_rating" AS "murmur_rating", "dbt_confidential_murmur"."responses"."started_at" AS "started_at", "dbt_confidential_murmur"."responses"."status" AS "status", "dbt_confidential_murmur"."responses"."submitted_at" AS "submitted_at", "dbt_confidential_murmur"."responses"."survey_id" AS "survey_id", "dbt_confidential_murmur"."responses"."type" AS "type", "dbt_confidential_murmur"."responses"."updated_at" AS "updated_at", "dbt_confidential_murmur"."responses"."user_agent" AS "user_agent", "dbt_confidential_murmur"."responses"."user_id" AS "user_id", "surveys__via__survey_id"."name" AS "name" FROM "dbt_confidential_murmur"."responses" LEFT JOIN "dbt_confidential_murmur"."surveys" "surveys__via__survey_id" ON "dbt_confidential_murmur"."responses"."survey_id" = "surveys__via__survey_id"."_id" LIMIT 2000

In this particular instance, when I run this as a SQL query in Metabase, it returns the results. However, I’ve experienced similar issues with the SQL interface also producing non-specific errors.

Diagnostic Info:

{
  "browser-info": {
    "language": "en-GB",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.3+7",
    "java.vendor": "AdoptOpenJDK",
    "java.vendor.url": "https://adoptopenjdk.net/",
    "java.version": "11.0.3",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.3+7",
    "os.name": "Linux",
    "os.version": "4.14.152-127.182.amzn2.x86_64",
    "user.language": "en",
    "user.timezone": "GMT"
  },
  "metabase-info": {
    "databases": [
      "presto",
      "mysql",
      "postgres"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "run-mode": "prod",
    "version": {
      "date": "2019-12-19",
      "tag": "v0.34.0",
      "branch": "release-0.34.x",
      "hash": "1335215"
    },
    "settings": {
      "report-timezone": "UTC"
    }
  }
}

Update 1: On a hunch, I tried removing the foreign key references in the data model. I can’t be sure, but I think removing the foreign keys for responses in the data model and then adding them back has resolved the issue. It seems to be working now.

Update 2: I think the change was not the foreign key relationships in the data model, but the “Display values” setting on the foreign key. When I edited the Survey ID to show the name from the surveys table, the error reoccured. So the issue seems to be with that particular feature.

Update 3: I’ve managed to pinpoint the exact broken display value to be Name. Using another field for the display value works fine. FWIW, the name column actually contains JSON, so perhaps some missing escape logic somewhere. Changing the type in the model from name to field containing JSON made no difference.

Update 4: I’ve managed to reproduce on the Surveys table, so it’s not the foreign key issue per se. If I keep all fields visible for the surveys table, a simple query of that table gives me the non-specific error. If I then hide all the columns I know to contain

Update 5: After hiding the offending columns in the Data Model, they longer appear, even after doing a new scan on the schema. However, SELECT name FROM dbt_confidential_murmur.surveys still works in SQL editor.

Hi @friendofasquid
With all the updates, I’m not sure if you’re still asking for help - if you are, what specifically?
You say that there’s an overlay and when clicking into log, it crashes the browser tab. That sounds a lot like you might have a CDN/proxy in front of Metabase that messes with it’s javascript (i.e CloudFlare) or a bad antivirus or browser extension.

Hi @flamber—with the updates, I think I’ve identified the root cause, which is Presto columns that contain JSON.

We have an AWS Application Load Balancer in front of Metabase. But this error persists across different browsers so probably not an extension issue.

Not sure how to proceed.

@friendofasquid There’s currently a Priority 1 issue with Presto in 0.34.0, so maybe that’s causing you the troubles?
https://github.com/metabase/metabase/issues/11598

I don’t think it’s the same issue because

  • we had the same issue with 0.33.4
  • general connectivity to presto seems fine, though we haven’t established a new connection to presto
  • the issue relates specifically to Presto columns that contain JSON

@friendofasquid
Interesting that you’re not seeing problems with your Presto. Which version are you using?

All the javascript errors in your first post, I’m fairly sure you can ignore those, since it’s just warnings.

But I would think that you should be seeing errors in the log (Admin > Troubleshooting > Logs), either when you are running the query or when try to sync/scan the database (Admin > Databases > your-presto-db)

Interesting that you’re not seeing problems with your Presto. Which version are you using?

I think this is because the connection was pre-existing, so successfully made the leap to 0.34. I tried install Metabase locally to see if I can recreate the issue, but wasn’t able to establish a new connect with 0.34. (I could when I downgraded my local Metabase to 0.33.4, but couldn’t query for unrelated issues)

But I would think that you should be seeing errors in the log (Admin > Troubleshooting > Logs), either when you are running the query or when try to sync/scan the database (Admin > Databases > your-presto-db)

Unfortunately, this page doesn’t load for me. I think the logs are too long, the browser just runs out of memory trying to show them to me. I have the same issue in Safari and Chrome. There very well might be errors there.

@friendofasquid Okay, just saw a lot of activity in the Presto bug, so thought it might be related, but good to know it isn’t.

The log should only load a few thousand lines max, so not sure why it’s crashing the browser. And the overlay thing you talked about, I have only heard about such weirdness, when there were some CDN/WAF that did some “magic”.
This is really strange, I’m not sure how to debug this.

It looks like you’re running Metabase in a Docker container, but you should be able to see the log with docker logs <metabase-container-name>

Was able to get the page loading in Firefox.

There are a lot of errors. Here’s one:

[1fd1f7a2-05df-4e20-a77c-c3b8566e34d0] 2020-01-03T01:00:21+11:00 ERROR metabase.sync.util Error running sync step: Assert failed: ((some-fn keyword? string?) driver)
("--> driver$the_driver.invokeStatic(driver.clj:97)"
 "driver$the_driver.invoke(driver.clj:97)"
 "driver$the_initialized_driver.invokeStatic(driver.clj:145)"
 "driver$the_initialized_driver.invoke(driver.clj:142)"
 "driver$dispatch_on_initialized_driver.invokeStatic(driver.clj:154)"
 "driver$dispatch_on_initialized_driver.doInvoke(driver.clj:149)"
 "driver$fn__21027$fn__21028.invoke(driver.clj:399)"
 "query_processor.timezone$report_timezone_id_if_supported.invokeStatic(timezone.clj:45)"
 "query_processor.timezone$report_timezone_id_if_supported.invoke(timezone.clj:38)"
 "query_processor.timezone$report_timezone_id_if_supported.invokeStatic(timezone.clj:42)"
 "query_processor.timezone$report_timezone_id_if_supported.invoke(timezone.clj:38)"
 "driver.presto$details__GT_request.invokeStatic(presto.clj:54)"
 "driver.presto$details__GT_request.invoke(presto.clj:49)"
 "driver.presto$execute_presto_query_BANG_$fn__318.invoke(presto.clj:101)"
 "util.ssh$with_ssh_tunnel_STAR_.invokeStatic(ssh.clj:106)"
 "util.ssh$with_ssh_tunnel_STAR_.invoke(ssh.clj:91)"
 "driver.presto$execute_presto_query_BANG_.invokeStatic(presto.clj:98)"
 "driver.presto$execute_presto_query_BANG_.invoke(presto.clj:94)"
 "driver.presto$eval380$database__GT_all_schemas__385$fn__391.invoke(presto.clj:150)"
 "driver.presto$eval380$database__GT_all_schemas__385.invoke(presto.clj:146)"
 "driver.presto$eval427$fn__428.invoke(presto.clj:164)"
 "sync.fetch_metadata$fn__51498$db_metadata__51503$fn__51504.invoke(fetch_metadata.clj:13)"
 "sync.fetch_metadata$fn__51498$db_metadata__51503.invoke(fetch_metadata.clj:10)"
 "sync.sync_metadata.tables$fn__52967$db_metadata__52972$fn__52973.invoke(tables.clj:146)"
 "sync.sync_metadata.tables$fn__52967$db_metadata__52972.invoke(tables.clj:143)"
 "sync.sync_metadata.tables$fn__53028$sync_tables_BANG___53033$fn__53034.invoke(tables.clj:163)"
 "sync.sync_metadata.tables$fn__53028$sync_tables_BANG___53033.invoke(tables.clj:158)"
 "sync.util$fn__43147$run_step_with_metadata__43152$fn__43156$fn__43158.invoke(util.clj:347)"
 "sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:102)"
 "sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:96)"
 "sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:119)"
 "sync.util$with_start_and_finish_debug_logging.invoke(util.clj:116)"
 "sync.util$fn__43147$run_step_with_metadata__43152$fn__43156.invoke(util.clj:344)"
 "sync.util$fn__43147$run_step_with_metadata__43152.invoke(util.clj:339)"
 "sync.util$fn__43339$run_sync_operation__43344$fn__43345$fn__43346.invoke(util.clj:432)"
 "sync.util$fn__43339$run_sync_operation__43344$fn__43345.invoke(util.clj:432)"
 "sync.util$fn__43339$run_sync_operation__43344.invoke(util.clj:426)"
 "sync.sync_metadata$fn__53081$sync_db_metadata_BANG___53086$fn__53087$fn__53088.invoke(sync_metadata.clj:51)"
 "sync.util$do_with_error_handling.invokeStatic(util.clj:147)"
 "sync.util$do_with_error_handling.invoke(util.clj:142)"
 "sync.util$do_with_error_handling.invokeStatic(util.clj:145)"
 "sync.util$do_with_error_handling.invoke(util.clj:142)"
 "driver$fn__21071.invokeStatic(driver.clj:522)"
 "driver$fn__21071.invoke(driver.clj:522)"
 "sync.util$sync_in_context$fn__43058.invoke(util.clj:138)"
 "sync.util$with_db_logging_disabled$fn__43055.invoke(util.clj:129)"
 "sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:102)"
 "sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:96)"
 "sync.util$with_start_and_finish_logging$fn__43044.invoke(util.clj:114)"
 "sync.util$with_sync_events$fn__43039.invoke(util.clj:88)"
 "sync.util$with_duplicate_ops_prevented$fn__43030.invoke(util.clj:67)"
 "sync.util$do_sync_operation.invokeStatic(util.clj:166)"
 "sync.util$do_sync_operation.invoke(util.clj:163)"
 "sync.sync_metadata$fn__53081$sync_db_metadata_BANG___53086$fn__53087.invoke(sync_metadata.clj:50)"
 "sync.sync_metadata$fn__53081$sync_db_metadata_BANG___53086.invoke(sync_metadata.clj:47)"
 "task.sync_databases.SyncAndAnalyzeDatabase.execute(sync_databases.clj:39)")

And lots and lots of this one:

[99608e2b-e076-45d1-a402-6bb8d0f65bbd] 2020-01-02T12:22:21+11:00 WARN metabase.query-processor.middleware.process-userland-query Query failure {:status :failed,
 :class java.util.concurrent.ExecutionException,
 :error
 "clojure.lang.ExceptionInfo: line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF> {:message \"line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>\", :errorCode 1, :errorName \"SYNTAX_ERROR\", :errorType \"USER_ERROR\", :errorLocation {:lineNumber 2, :columnNumber 185}, :failureInfo {:type \"com.facebook.presto.sql.parser.ParsingException\", :message \"line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>\", :cause {:type \"org.antlr.v4.runtime.InputMismatchException\", :suppressed [], :stack [\"com.facebook.presto.sql.parser.SqlParser$2.recoverInline(SqlParser.java:139)\" \"org.antlr.v4.runtime.Parser.match(Parser.java:206)\" \"com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:242)\" \"com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)\" \"com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)\" \"com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)\" \"com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)\" \"com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)\" \"com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)\" \"java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\" \"java.util.concurrent.FutureTask.run(FutureTask.java:266)\" \"java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\" \"java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\" \"java.lang.Thread.run(Thread.java:748)\"]}, :suppressed [], :stack [\"com.facebook.presto.sql.parser.ErrorHandler.syntaxError(ErrorHandler.java:109)\" \"org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41)\" \"org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544)\" \"org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327)\" \"org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139)\" \"com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:247)\" \"com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)\" \"com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)\" \"com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)\" \"com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)\" \"com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)\" \"com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)\" \"java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\" \"java.util.concurrent.FutureTask.run(FutureTask.java:266)\" \"java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\" \"java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\" \"java.lang.Thread.run(Thread.java:748)\"], :errorLocation {:lineNumber 2, :columnNumber 185}}}",
 :stacktrace
 ("java.base/java.util.concurrent.FutureTask.report(Unknown Source)"
  "java.base/java.util.concurrent.FutureTask.get(Unknown Source)"
  "clojure.core$deref_future.invokeStatic(core.clj:2300)"
  "clojure.core$future_call$reify__8454.deref(core.clj:6974)"
  "clojure.core$deref.invokeStatic(core.clj:2320)"
  "clojure.core$deref.invoke(core.clj:2306)"
  "--> driver.presto$execute_presto_query_BANG_$fn__318.invoke(presto.clj:114)"
  "util.ssh$with_ssh_tunnel_STAR_.invokeStatic(ssh.clj:106)"
  "util.ssh$with_ssh_tunnel_STAR_.invoke(ssh.clj:91)"
  "driver.presto$execute_presto_query_BANG_.invokeStatic(presto.clj:98)"
  "driver.presto$execute_presto_query_BANG_.invoke(presto.clj:94)"
  "driver.presto$eval514$fn__516.invoke(presto.clj:243)"
  "query_processor$fn__45782$execute_query__45787$fn__45788.invoke(query_processor.clj:69)"
  "query_processor$fn__45782$execute_query__45787.invoke(query_processor.clj:64)"
  "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__23057.invoke(mbql_to_native.clj:40)"
  "query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__39600.invoke(annotate.clj:541)"
  "query_processor.middleware.annotate$add_column_info$fn__39506.invoke(annotate.clj:485)"
  "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__40540.invoke(cumulative_aggregations.clj:57)"
  "query_processor.middleware.resolve_joins$resolve_joins$fn__42873.invoke(resolve_joins.clj:184)"
  "query_processor.middleware.limit$limit$fn__41651.invoke(limit.clj:19)"
  "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__45642.invoke(results_metadata.clj:87)"
  "query_processor.middleware.format_rows$format_rows$fn__41639.invoke(format_rows.clj:76)"
  "query_processor.middleware.add_dimension_projections$add_remapping$fn__37181.invoke(add_dimension_projections.clj:232)"
  "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__37904.invoke(add_source_metadata.clj:107)"
  "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__42923.invoke(resolve_source_table.clj:46)"
  "query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__37741.invoke(add_row_count_and_status.clj:16)"
  "query_processor.middleware.driver_specific$process_query_in_context$fn__40615.invoke(driver_specific.clj:12)"
  "query_processor.middleware.resolve_driver$resolve_driver$fn__42537.invoke(resolve_driver.clj:22)"
  "query_processor.middleware.store$initialize_store$fn__45667$fn__45668.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__45667.invoke(store.clj:10)"
  "query_processor.middleware.async$async__GT_sync$fn__22968.invoke(async.clj:23)"
  "query_processor.middleware.async_wait$runnable$fn__39657.invoke(async_wait.clj:89)"),
 :query
 {:native
  {:query
   "SELECT \"dbt_confidential_murmur\".\"responses\".\"_id\" AS \"_id\", \"dbt_confidential_murmur\".\"responses\".\"created_at\" AS \"created_at\", \"dbt_confidential_murmur\".\"responses\".\"demonstration\" A...\n",
   :template-tags {}},
  :type "native",
  :parameters [],
  :async? true,
  :middleware {:add-default-userland-constraints? true, :userland-query? true},
  :info
  {:executed-by 4,
   :context :ad-hoc,
   :card-id nil,
   :nested? false,
   :query-hash [-11, 116, 82, 32, 22, -76, 123, -8, 29, -27, 112, -51, -21, 36, 48, -92, 72, -73, 46, -117, -43, -12, 46, -82, -55, -94, -97, 82, 79, 33, -91, 65]},
  :constraints {:max-results 10000, :max-results-bare-rows 2000}},
 :cause
 {:class clojure.lang.ExceptionInfo,
  :error "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
  :ex-data
  {:message "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
   :errorCode 1,
   :errorName "SYNTAX_ERROR",
   :errorType "USER_ERROR",
   :errorLocation {:lineNumber 2, :columnNumber 185},
   :failureInfo
   {:type "com.facebook.presto.sql.parser.ParsingException",
    :message "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
    :cause
    {:type "org.antlr.v4.runtime.InputMismatchException",
     :suppressed [],
     :stack
     ["com.facebook.presto.sql.parser.SqlParser$2.recoverInline(SqlParser.java:139)"
      "org.antlr.v4.runtime.Parser.match(Parser.java:206)"
      "com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:242)"
      "com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)"
      "com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)"
      "com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)"
      "com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)"
      "com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)"
      "com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)"
      "java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)"
      "java.util.concurrent.FutureTask.run(FutureTask.java:266)"
      "java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)"
      "java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)"
      "java.lang.Thread.run(Thread.java:748)"]},
    :suppressed [],
    :stack
    ["com.facebook.presto.sql.parser.ErrorHandler.syntaxError(ErrorHandler.java:109)"
     "org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41)"
     "org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544)"
     "org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327)"
     "org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139)"
     "com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:247)"
     "com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)"
     "com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)"
     "com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)"
     "com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)"
     "com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)"
     "com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)"
     "java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)"
     "java.util.concurrent.FutureTask.run(FutureTask.java:266)"
     "java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)"
     "java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)"
     "java.lang.Thread.run(Thread.java:748)"],
    :errorLocation {:lineNumber 2, :columnNumber 185}}}}}

@friendofasquid The first error is issue 11598.
The second error looks like a syntax error, and the :query seems to be truncated, which could be the reason, but maybe you did that to redact it?

I didn’t redact, and that exact truncated query appears multiple times in the logs. I was say there are hundreds of that same error message with the same partial query.

@friendofasquid Right before of after the error, you should see a request with the same timestamp that is causing this error. Like DEBUG middleware.log :: POST /api/...

Here is immediately before and after, plus error:

[99608e2b-e076-45d1-a402-6bb8d0f65bbd] 2020-01-02T12:22:21+11:00 DEBUG metabase.middleware.log POST /api/dataset 200 [ASYNC: completed] 474.3 ms (9 DB calls) Jetty threads: 2/50 (13 idle, 0 queued) (68 total active threads) Queries in flight: 1
[99608e2b-e076-45d1-a402-6bb8d0f65bbd] 2020-01-02T12:22:21+11:00 WARN metabase.query-processor.middleware.process-userland-query Query failure {:status :failed,
 :class java.util.concurrent.ExecutionException,
 :error
 "clojure.lang.ExceptionInfo: line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF> {:message \"line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>\", :errorCode 1, :errorName \"SYNTAX_ERROR\", :errorType \"USER_ERROR\", :errorLocation {:lineNumber 2, :columnNumber 185}, :failureInfo {:type \"com.facebook.presto.sql.parser.ParsingException\", :message \"line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>\", :cause {:type \"org.antlr.v4.runtime.InputMismatchException\", :suppressed [], :stack [\"com.facebook.presto.sql.parser.SqlParser$2.recoverInline(SqlParser.java:139)\" \"org.antlr.v4.runtime.Parser.match(Parser.java:206)\" \"com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:242)\" \"com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)\" \"com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)\" \"com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)\" \"com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)\" \"com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)\" \"com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)\" \"java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\" \"java.util.concurrent.FutureTask.run(FutureTask.java:266)\" \"java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\" \"java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\" \"java.lang.Thread.run(Thread.java:748)\"]}, :suppressed [], :stack [\"com.facebook.presto.sql.parser.ErrorHandler.syntaxError(ErrorHandler.java:109)\" \"org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41)\" \"org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544)\" \"org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327)\" \"org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139)\" \"com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:247)\" \"com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)\" \"com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)\" \"com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)\" \"com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)\" \"com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)\" \"com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)\" \"java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\" \"java.util.concurrent.FutureTask.run(FutureTask.java:266)\" \"java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\" \"java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\" \"java.lang.Thread.run(Thread.java:748)\"], :errorLocation {:lineNumber 2, :columnNumber 185}}}",
 :stacktrace
 ("java.base/java.util.concurrent.FutureTask.report(Unknown Source)"
  "java.base/java.util.concurrent.FutureTask.get(Unknown Source)"
  "clojure.core$deref_future.invokeStatic(core.clj:2300)"
  "clojure.core$future_call$reify__8454.deref(core.clj:6974)"
  "clojure.core$deref.invokeStatic(core.clj:2320)"
  "clojure.core$deref.invoke(core.clj:2306)"
  "--> driver.presto$execute_presto_query_BANG_$fn__318.invoke(presto.clj:114)"
  "util.ssh$with_ssh_tunnel_STAR_.invokeStatic(ssh.clj:106)"
  "util.ssh$with_ssh_tunnel_STAR_.invoke(ssh.clj:91)"
  "driver.presto$execute_presto_query_BANG_.invokeStatic(presto.clj:98)"
  "driver.presto$execute_presto_query_BANG_.invoke(presto.clj:94)"
  "driver.presto$eval514$fn__516.invoke(presto.clj:243)"
  "query_processor$fn__45782$execute_query__45787$fn__45788.invoke(query_processor.clj:69)"
  "query_processor$fn__45782$execute_query__45787.invoke(query_processor.clj:64)"
  "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__23057.invoke(mbql_to_native.clj:40)"
  "query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__39600.invoke(annotate.clj:541)"
  "query_processor.middleware.annotate$add_column_info$fn__39506.invoke(annotate.clj:485)"
  "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__40540.invoke(cumulative_aggregations.clj:57)"
  "query_processor.middleware.resolve_joins$resolve_joins$fn__42873.invoke(resolve_joins.clj:184)"
  "query_processor.middleware.limit$limit$fn__41651.invoke(limit.clj:19)"
  "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__45642.invoke(results_metadata.clj:87)"
  "query_processor.middleware.format_rows$format_rows$fn__41639.invoke(format_rows.clj:76)"
  "query_processor.middleware.add_dimension_projections$add_remapping$fn__37181.invoke(add_dimension_projections.clj:232)"
  "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__37904.invoke(add_source_metadata.clj:107)"
  "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__42923.invoke(resolve_source_table.clj:46)"
  "query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__37741.invoke(add_row_count_and_status.clj:16)"
  "query_processor.middleware.driver_specific$process_query_in_context$fn__40615.invoke(driver_specific.clj:12)"
  "query_processor.middleware.resolve_driver$resolve_driver$fn__42537.invoke(resolve_driver.clj:22)"
  "query_processor.middleware.store$initialize_store$fn__45667$fn__45668.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__45667.invoke(store.clj:10)"
  "query_processor.middleware.async$async__GT_sync$fn__22968.invoke(async.clj:23)"
  "query_processor.middleware.async_wait$runnable$fn__39657.invoke(async_wait.clj:89)"),
 :query
 {:native
  {:query
   "SELECT \"dbt_confidential_murmur\".\"responses\".\"_id\" AS \"_id\", \"dbt_confidential_murmur\".\"responses\".\"created_at\" AS \"created_at\", \"dbt_confidential_murmur\".\"responses\".\"demonstration\" A...\n",
   :template-tags {}},
  :type "native",
  :parameters [],
  :async? true,
  :middleware {:add-default-userland-constraints? true, :userland-query? true},
  :info
  {:executed-by 4,
   :context :ad-hoc,
   :card-id nil,
   :nested? false,
   :query-hash [-11, 116, 82, 32, 22, -76, 123, -8, 29, -27, 112, -51, -21, 36, 48, -92, 72, -73, 46, -117, -43, -12, 46, -82, -55, -94, -97, 82, 79, 33, -91, 65]},
  :constraints {:max-results 10000, :max-results-bare-rows 2000}},
 :cause
 {:class clojure.lang.ExceptionInfo,
  :error "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
  :ex-data
  {:message "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
   :errorCode 1,
   :errorName "SYNTAX_ERROR",
   :errorType "USER_ERROR",
   :errorLocation {:lineNumber 2, :columnNumber 185},
   :failureInfo
   {:type "com.facebook.presto.sql.parser.ParsingException",
    :message "line 2:185: mismatched input '.'. Expecting: ',', 'EXCEPT', 'FROM', 'GROUP', 'HAVING', 'INTERSECT', 'LIMIT', 'ORDER', 'UNION', 'WHERE', <EOF>",
    :cause
    {:type "org.antlr.v4.runtime.InputMismatchException",
     :suppressed [],
     :stack
     ["com.facebook.presto.sql.parser.SqlParser$2.recoverInline(SqlParser.java:139)"
      "org.antlr.v4.runtime.Parser.match(Parser.java:206)"
      "com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:242)"
      "com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)"
      "com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)"
      "com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)"
      "com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)"
      "com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)"
      "com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)"
      "java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)"
      "java.util.concurrent.FutureTask.run(FutureTask.java:266)"
      "java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)"
      "java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)"
      "java.lang.Thread.run(Thread.java:748)"]},
    :suppressed [],
    :stack
    ["com.facebook.presto.sql.parser.ErrorHandler.syntaxError(ErrorHandler.java:109)"
     "org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41)"
     "org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544)"
     "org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327)"
     "org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139)"
     "com.facebook.presto.sql.parser.SqlBaseParser.singleStatement(SqlBaseParser.java:247)"
     "com.facebook.presto.sql.parser.SqlParser.invokeParser(SqlParser.java:162)"
     "com.facebook.presto.sql.parser.SqlParser.createStatement(SqlParser.java:98)"
     "com.facebook.presto.execution.QueryPreparer.prepareQuery(QueryPreparer.java:56)"
     "com.facebook.presto.execution.SqlQueryManager.createQueryInternal(SqlQueryManager.java:343)"
     "com.facebook.presto.execution.SqlQueryManager.lambda$createQuery$4(SqlQueryManager.java:305)"
     "com.facebook.presto.$gen.Presto_0_224____20191212_060105_1.run(Unknown Source)"
     "java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)"
     "java.util.concurrent.FutureTask.run(FutureTask.java:266)"
     "java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)"
     "java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)"
     "java.lang.Thread.run(Thread.java:748)"],
    :errorLocation {:lineNumber 2, :columnNumber 185}}}}}

[99608e2b-e076-45d1-a402-6bb8d0f65bbd] 2020-01-02T12:22:21+11:00 DEBUG metabase.middleware.log POST /api/dataset 200 [ASYNC: completed] 340.4 ms (8 DB calls) Jetty threads: 2/50 (13 idle, 0 queued) (68 total active threads) Queries in flight: 0
[99608e2b-e076-45d1-a402-6bb8d0f65bbd] 2020-01-02T12:22:21+11:00 WARN metabase.query-processor.middleware.process-userland-query Query failure {:status :failed,

@friendofasquid Okay, I’m guessing a user with ID 4 is executing a wrong query.
But are these errors even related to your initial problem? Please try to reproduce the problem and then check the log (verify the timestamp).

I actually cannot reproduce the original error. The original error was caused by the default query in a simple question including some JSON columns. I hid those columns, and they are no longer present in the model (despite being present in the database). So now the primary issue is those missing columns.

Once those columns can appear again in the data model, I can attempt to reproduce the original issue.

User #4 is me; I can assure you have not run that same query many dozens of times with syntax error.

Perhaps issue 11598 needs to be fixed, then I can see those columns again in the data model, then I can reproduce the issue. That would probably work better for me than downgrading in order to reproduce.

@friendofasquid

Okay, there might be something with Presto and JSON-columns (there has been issues with other databases), but I don’t use Presto, so it would help a lot if you can get the log from when the error occurs.

As for not being able to restore hidden columns in the Data Model, that’s an existing issue (with a workaround by editing the metadata):
https://github.com/metabase/metabase/issues/10297 - upvote by clicking :+1: on the first post

I’m not completely sure what’s going on with your setup, but I would highly recommend that you try to run the MacApp as a test and just use the Sample Dataset. It’s just so you can see that there’s no overlay and the logs don’t crash.
I have a feeling that some javascript is getting messed up, which might be why you’re seeing many dozens of queries with wrong syntax.

I’ve used a work-around to re-able the hidden columns. I haven’t been able to reproduce the issue :frowning:

FWIW, the columns were not JSON. They were complex types (one was a MAP<VARCHAR, VARCHAR> and the other was of type ROW) but I had them set as Field Containing JSON. I mention only in case it helps someone else debug or reproduce.

I’ve changed some of the modelling on our end to help, but I am now blocked by https://github.com/metabase/metabase/issues/11598

I can reproduce by setting foreign key display value to reference a complex type in another table. However, I’m really not seeing anything at all in the logs that would help to troubleshoot this.

What I can see in the Chrome inspector is that the dataset call successfully retrieves the records and the JSON in the response seems to be well-formed. This looks very much like an exclusively client-side error based on back-end configuration.

I’m not sure if I can get you anything more helpful on this issue, but please let me know if I can.