Metabase got significantly slower after upgrading to 0.42.0

alextran78 · March 11, 2022, 8:22am

Hi, we recently upgraded our Metabase to 0.42.0. Since then, everything load a lot slower than it was before. Here is what we see in logs

[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T08:02:27+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T08:02:27+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T08:02:27+00:00 DEBUG metabase.server.middleware.log POST /api/dashboard/148/dashcard/1116/card/1101/query 202 [ASYNC: completed] 2.2 mins (21 DB calls) App DB connections: 8/15 Jetty threads: 13/50 (6 idle, 0 queued) (170 total active threads) Queries in flight: 46 (0 queued); sqlserver DB 3 connections: 3/5 (0 threads blocked)

We have 2 instances of Metabase: Production and Non-Production. We tested the upgrade on Non-Production and didn't see any issue. The log on non-production is also different. Here is a copy of the non-production log

[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:32+00:00 DEBUG metabase.server.middleware.log GET /api/session/properties 200 29.4 ms (4 DB calls) App DB connections: 1/15 Jetty threads: 6/50 (2 idle, 0 queued) (136 total active threads) Queries in flight: 0 (0 queued)
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:32+00:00 DEBUG metabase.server.middleware.log GET /api/setting 200 34.8 ms (3 DB calls) App DB connections: 0/15 Jetty threads: 6/50 (2 idle, 0 queued) (136 total active threads) Queries in flight: 0 (0 queued)
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:32+00:00 DEBUG metabase.server.middleware.log GET /api/setup/admin_checklist 200 21.5 ms (11 DB calls) App DB connections: 0/15 Jetty threads: 5/50 (3 idle, 0 queued) (136 total active threads) Queries in flight: 0 (0 queued)
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:34+00:00 DEBUG metabase.server.middleware.log GET /api/util/bug_report_details 200 3.6 ms (1 DB calls) App DB connections: 0/15 Jetty threads: 5/50 (3 idle, 0 queued) (136 total active threads) Queries in flight: 0 (0 queued)
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:34+00:00 INFO metabase.server.middleware.exceptions Request canceled before finishing.
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:34+00:00 INFO metabase.server.middleware.exceptions Request canceled before finishing.
[68e45f7d-e615-4839-ac16-e74ca6182003] 2022-03-11T08:10:44+00:00 INFO metabase.server.middleware.exceptions Request canceled before finishing.

We are deploying our Metabase on AKS via helm chart. The backend is MySQL database.

flamber · March 11, 2022, 8:55am

Hi @alextran78

Post "Diagnostic Info" from Admin > Troubleshooting. Latest release is 0.42.2
Which version did you upgrade from?
Your logs show that there are a lot of queries in flight, but the tiny log snippet is not enough to understand the full picture.

alextran78 · March 11, 2022, 9:09am

hi, thanks for the reply. Here is our Diagnostic Info

{
  "browser-info": {
    "language": "en-GB",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:97.0) Gecko/20100101 Firefox/97.0",
    "vendor": ""
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.14+9",
    "java.vendor": "Eclipse Adoptium",
    "java.vendor.url": "https://adoptium.net/",
    "java.version": "11.0.14",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.14+9",
    "os.name": "Linux",
    "os.version": "5.4.0-1043-azure",
    "user.language": "en",
    "user.timezone": "UTC"
  },
  "metabase-info": {
    "databases": [
      "h2",
      "sqlserver",
      "mysql"
    ],
    "hosting-env": "unknown",
    "application-database": "mysql",
    "application-database-details": {
      "database": {
        "name": "MySQL",
        "version": "5.6.47.0"
      },
      "jdbc-driver": {
        "name": "MariaDB Connector/J",
        "version": "2.6.2"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2022-02-08",
      "tag": "v0.42.0",
      "branch": "release-x.42.x",
      "hash": "de1264e"
    },
    "settings": {
      "report-timezone": "Europe/London"
    }
  }
}

We upgraded from 0.36.3

Do you want me to post more logs?

flamber · March 11, 2022, 9:19am

@alextran78
Metabase does not support MySQL 5.6:
https://www.metabase.com/docs/latest/operations-guide/configuring-application-database.html#mysql-or-mariadb

Latest release is 0.42.2: https://github.com/metabase/metabase/releases/latest

And without more logs, then I cannot see what is going on.

alextran78 · March 11, 2022, 9:57am

hi, here are all the logs I'm seeing atm

[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 DEBUG metabase.server.middleware.log GET /api/user/current 200 8.2 ms (4 DB calls) App DB connections: 8/15 Jetty threads: 13/50 (7 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 DEBUG metabase.server.middleware.log GET /api/session/properties 200 182.3 ms (3 DB calls) App DB connections: 9/15 Jetty threads: 15/50 (5 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 DEBUG metabase.server.middleware.log GET /api/database 200 17.8 ms (4 DB calls) App DB connections: 8/15 Jetty threads: 15/50 (5 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:01+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 DEBUG metabase.server.middleware.log GET /api/dashboard/85 200 1.5 s (38 DB calls) App DB connections: 7/15 Jetty threads: 13/50 (7 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 DEBUG metabase.server.middleware.log GET /api/table/card__764/query_metadata 200 16.6 ms (6 DB calls) App DB connections: 7/15 Jetty threads: 14/50 (6 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 DEBUG metabase.server.middleware.log GET /api/table/card__753/query_metadata 200 16.5 ms (5 DB calls) App DB connections: 7/15 Jetty threads: 14/50 (6 idle, 0 queued) (155 total active threads) Queries in flight: 46 (0 queued)
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:02+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException
[c3afbaf6-5667-486f-a992-6abf06552a51] 2022-03-11T09:48:03+00:00 ERROR metabase.async.streaming-response Error determining whether HTTP request was canceled
java.lang.ClassCastException

If our current version of MySQL isn't supported, what are our options? Do we need to migrate to another DB? How complex would this be?

flamber · March 11, 2022, 10:23am

@alextran78 MySQL 5.6 has not been supported since 0.32, so for several years.
And is also end-of-life https://endoflife.date/mysql, so you should upgrade no matter what.

I don't know your setup or how many active users you have, but there is a lot of activity.

The error Error determining whether HTTP request was canceled can be caused by using Jetty SSL, so if you are using that, then ignore it (or create a custom Log4j, which filters it out).
But it could also be caused by incorrect reverse-proxy or incorrect health checks.

alextran78 · March 11, 2022, 10:34am

hi, I've checked our current MySQL server version on Azure that we're using for Metabase and it's saying that it's 8.0. I'm including a few screenshots below

flamber · March 11, 2022, 10:45am

@alextran78 The version the application database says it is, which Metabase receives during connection negotiation is 5.6.47.0, so I guess that it is some custom version of MySQL that Azure is running with some hacks, which causes problems during negotiation with some clients.

Anyhow, I cannot tell from your logs what the problem is. Either you are not including everything or the problem is elsewhere. I already pointed out that there's massive activity, so if you only have a couple of users, then something is wrong.

alextran78 · March 11, 2022, 1:14pm

We do have quite a few users. That's all I can see from the logs. Is there any more diagnostic information I can provide?

flamber · March 11, 2022, 1:32pm

@alextran78 That gives me absolutely no information. What is "quite a few" - 5, 500, 5000, ...?
You need to provide numbers, so it's possibly to understand your setup.

And you need to provide logs and actually indicate the problem. I've already commented multiple times.

There are more than 40,000 setups of Metabase, and some with many thousands of users, and several hundred concurrent active users.
Read this: https://www.metabase.com/learn/administration/metabase-at-scale.html

And then debug your setup, so you can understand where the problem is and then you can return, when you have more information.