metabase
Metabase grinds to a halt after a week or so - Performance issue when upgrade from 56 to 57
Describe the bug
Hi,
I'm facing issues where every so often my metabase instance is just grinding to a halt and going super slow and not working with cards ending up saying there was a problem. I've looked into logs and I see everything is taking time, but I can't pinpoint why.
To Reproduce
Restarting metabase tends to fix the issue
Expected behavior
Speed
Logs
2025-11-28 08:17:33,930 DEBUG middleware.log :: [32mGET /api/user/current 200 38ms (10 DB calls) App DB connections: 4/15 Jetty threads: 5/50 (32 idle, 0 queued) (140 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:33,935 DEBUG middleware.log :: [32mGET /api/session/properties 200 669ms (13 DB calls) App DB connections: 0/15 Jetty threads: 6/50 (32 idle, 0 queued) (141 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:34,552 DEBUG middleware.log :: [32mGET /api/database 200 499ms (3 DB calls) App DB connections: 6/15 Jetty threads: 11/50 (27 idle, 0 queued) (141 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:34,555 DEBUG middleware.log :: [32mGET /api/bookmark 200 489ms (1 DB calls) App DB connections: 6/15 Jetty threads: 11/50 (27 idle, 0 queued) (141 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:34,565 DEBUG middleware.log :: [32mGET /api/collection/tree 200 511ms (4 DB calls) App DB connections: 10/15 Jetty threads: 11/50 (27 idle, 0 queued) (143 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:34,572 DEBUG middleware.log :: [32mGET /api/collection/root 200 524ms (5 DB calls) App DB connections: 6/15 Jetty threads: 11/50 (27 idle, 0 queued) (144 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:34,588 DEBUG middleware.log :: [32mGET /api/collection/trash 200 50ms (3 DB calls) App DB connections: 5/15 Jetty threads: 10/50 (27 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:35,532 WARN queries.schema :: Ignoring invalid Card result_metadata 2025-11-28 08:17:35,999 DEBUG middleware.log :: [32mGET /api/setting/version-info 200 4ms (0 DB calls) App DB connections: 5/15 Jetty threads: 8/50 (29 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:36,003 DEBUG middleware.log :: [32mGET /api/activity/popular_items 200 1438ms (12 DB calls) App DB connections: 4/15 Jetty threads: 8/50 (29 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:36,026 DEBUG middleware.log :: [32mGET /api/search 200 1480ms (7 DB calls) App DB connections: 3/15 Jetty threads: 8/50 (29 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:36,030 DEBUG middleware.log :: [32mGET /api/database 200 500ms (3 DB calls) App DB connections: 3/15 Jetty threads: 7/50 (29 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:36,487 DEBUG middleware.log :: [32mGET /api/activity/recents 200 1939ms (29 DB calls) App DB connections: 0/15 Jetty threads: 5/50 (30 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:49,416 DEBUG middleware.log :: [32mGET /api/dashboard/37 200 4545ms (36 DB calls) App DB connections: 2/15 Jetty threads: 5/50 (31 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:49,434 DEBUG middleware.log :: [32mGET /api/dashboard/37/query_metadata 200 4559ms (13 DB calls) App DB connections: 0/15 Jetty threads: 5/50 (31 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:49,550 DEBUG middleware.log :: [32mGET /api/pulse/form_input 200 8ms (1 DB calls) App DB connections: 9/15 Jetty threads: 18/50 (17 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:50,028 DEBUG middleware.log :: [32mGET /api/collection/6 200 483ms (6 DB calls) App DB connections: 15/15 Jetty threads: 17/50 (19 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:17:53,973 DEBUG middleware.log :: [32mGET /api/collection/5 200 3466ms (4 DB calls) App DB connections: 15/15 Jetty threads: 17/50 (19 idle, 0 queued) (145 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:18:23,332 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 15.5 s 2025-11-28 08:18:30,143 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.expand-macros/expand-macros took 6.4 s 2025-11-28 08:18:34,585 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-referenced/resolve-referenced-card-resources took 4.4 s 2025-11-28 08:18:39,958 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.expand-macros/expand-macros took 3.7 s 2025-11-28 08:18:40,354 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.parameters/substitute-parameters took 4.1 s 2025-11-28 08:18:56,583 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/215/card/114/query 202 [ASYNC: canceled] 67032ms (17 DB calls) App DB connections: 14/15 Jetty threads: 13/50 (22 idle, 0 queued) (140 total active threads) Queries in flight: 4 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:01,510 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/267/card/146/query 202 [ASYNC: canceled] 71027ms (13 DB calls) App DB connections: 14/15 Jetty threads: 8/50 (25 idle, 0 queued) (141 total active threads) Queries in flight: 7 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:01,517 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/213/card/113/query 202 [ASYNC: canceled] 71964ms (13 DB calls) App DB connections: 13/15 Jetty threads: 9/50 (24 idle, 0 queued) (141 total active threads) Queries in flight: 5 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:03,039 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/269/card/148/query 202 [ASYNC: canceled] 73056ms (16 DB calls) App DB connections: 6/15 Jetty threads: 8/50 (25 idle, 0 queued) (142 total active threads) Queries in flight: 3 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:03,039 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/285/card/153/query 202 [ASYNC: canceled] 73484ms (13 DB calls) App DB connections: 6/15 Jetty threads: 8/50 (25 idle, 0 queued) (142 total active threads) Queries in flight: 3 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:05,120 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.wrap-value-literals/wrap-value-literals took 1.1 s 2025-11-28 08:19:08,227 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/268/card/147/query 202 [ASYNC: canceled] 77838ms (14 DB calls) App DB connections: 3/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 6 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:08,228 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/212/card/82/query 202 [ASYNC: canceled] 78686ms (13 DB calls) App DB connections: 2/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 6 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:08,675 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/226/card/84/query 202 [ASYNC: canceled] 78688ms (13 DB calls) App DB connections: 1/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 5 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:09,179 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/286/card/154/query 202 [ASYNC: canceled] 79123ms (13 DB calls) App DB connections: 1/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 4 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:09,629 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/223/card/129/query 202 [ASYNC: canceled] 80075ms (13 DB calls) App DB connections: 1/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 3 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:10,071 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/217/card/127/query 202 [ASYNC: canceled] 80515ms (13 DB calls) App DB connections: 2/15 Jetty threads: 4/50 (28 idle, 0 queued) (141 total active threads) Queries in flight: 2 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:10,112 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/221/card/128/query 202 [ASYNC: canceled] 80557ms (13 DB calls) App DB connections: 2/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 2 (0 queued) {:metabase-user-id 1}[0m 2025-11-28 08:19:10,632 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/214/card/126/query 202 [ASYNC: canceled] 80643ms (13 DB calls) App DB connections: 1/15 Jetty threads: 3/50 (29 idle, 0 queued) (141 total active threads) Queries in flight: 1 (0 queued) {:metabase-user-id 1}[0m
Information about your Metabase installation
{
"browser-info": {
"language": "en-GB",
"platform": "MacIntel",
"userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36",
"vendor": "Google Inc."
},
"metabase-info": {
"databases": [
"postgres"
],
"run-mode": "prod",
"plan-alias": "",
"version": {
"date": "2025-11-19",
"tag": "v0.57.3",
"hash": "6b828bd"
},
"settings": {
"report-timezone": null
},
"hosting-env": "unknown",
"application-database": "postgres",
"application-database-details": {
"database": {
"name": "PostgreSQL",
"version": "15.15"
},
"jdbc-driver": {
"name": "PostgreSQL JDBC Driver",
"version": "42.7.7"
}
}
},
"system-info": {
"file.encoding": "UTF-8",
"java.runtime.name": "OpenJDK Runtime Environment",
"java.runtime.version": "21.0.9+10-LTS",
"java.vendor": "Eclipse Adoptium",
"java.vendor.url": "https://adoptium.net/",
"java.version": "21.0.9",
"java.vm.name": "OpenJDK 64-Bit Server VM",
"java.vm.version": "21.0.9+10-LTS",
"os.name": "Linux",
"os.version": "4.18.0-553.80.1.el8_10.x86_64",
"user.language": "en",
"user.timezone": "GMT"
}
}
Severity
High
Additional context
This seems to happen on all dashboards, even just normal metabase pages.
My server where metabase & pgsql is hosted hasn't had any memory or cpu issues. The metabase docker container has 3gb ram of which 1.3gb is used and has 4 cpu cores of which 0.2% is used on average - these have stayed consistent.
Seconded.
Memory leak it seems. Noticed memory consumption increases gradually until reaching a point when CPU consumption is 100% continuously.
On-Premise Dockerized v1.57.3 hosted on cloud. Connected to PostgreSQL and ClickhouseDB.
Issue started after upgrade from v1.56.13 to v1.57.3
We have to restart the instance every day or two
@shivampaw the logs that you added above don't contain any information relevant to the issue
@marcekalowe we need a heap dump
Also @shivampaw how are you deploying metabase? Is metabase application DB a standalone Database or it's being used by other systems?
How much RAM and CPU is allocated to Metabase?
56.13 was also the last stable version I had. It started since i upgraded to 56.14, so I downgraded. 57.x also has the issue though.
Single Server with Metabase running on docker And a PG DB server on that server too.
Server is 8GB ram and 8 CPU cores with 3GB ram and 4 CPU cores allocated to the metabase container.
The only other system using the Postgres DB is a separate script which runs once a day to put data into the DB. It’s just shifting from a few 3rd party APIs. Pretty low volume, not intensive.
@Tony-metabase
I can try get a deeper dump for you @paoliniluis What would help exactly?
Same issue after upgrade to 0.57.3. Looks like a memory leak. Have been running Metabase in a docker container for many years and never had this issue before. We can physically see the memory leak in the graph once users start using the dashboards.
Once the Java/Heap memory runs out, the CPU starts to thrash and the server returns 504.
I increased the HEAP from the default 1GB to 2GB to give us a bit more headroom.
4 GB of system memory x2 CPU cores. (AWS c6i.large). Nothing else besides docker and Metabase running on the instance
@ambro-devprox is that chart from the server or from the Metabase application (retrieved from prometheus metrics or an agent)?
@paoliniluis That is the host instance that runs the docker. Metrics are obtained via Amazon CloudWatch Agent
@ambro-devprox ok so that metric is wrong, since that's the memory of the host which might not indicate the memory that the guest (in this case the JVM and inside the JVM the Metabase application) is using.
you need to monitor the application memory usage, not the host, since a JVM will allocate as much memory as possible and ALMOST never release it. We've written some docs about that I think
Sure. Whatever you say must be correct then.
For those who still believe there is a possibility that a memory leak has been introduced: Here is a screenshot of the CPU thrashing (this was before I increased the heap to 2GB). ENV JAVA_OPTS="-Xmx2g -Xms1g -XX:+UseG1GC"
Not enough time has passed for the system to crash again.
It's happening again to me now - 504s came.
These are the best logs I have from metabase docker:
2025-12-06 08:40:13,291 DEBUG middleware.log :: [32mGET /api/session/properties 200 131ms (13 DB calls) App DB connections: 2/7 Jetty threads: 5/50 (11 idle, 0 queued) (124 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:13,755 DEBUG middleware.log :: [32mGET /api/user/current 200 583ms (10 DB calls) App DB connections: 1/7 Jetty threads: 5/50 (11 idle, 0 queued) (124 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:13,948 DEBUG middleware.log :: [32mGET /api/bookmark 200 26ms (1 DB calls) App DB connections: 7/7 Jetty threads: 13/50 (3 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:14,000 DEBUG middleware.log :: [32mGET /api/collection/tree 200 76ms (4 DB calls) App DB connections: 12/13 Jetty threads: 12/50 (3 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:14,526 DEBUG middleware.log :: [32mGET /api/database 200 575ms (3 DB calls) App DB connections: 12/13 Jetty threads: 10/50 (3 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:15,029 DEBUG middleware.log :: [32mGET /api/collection/trash 200 1101ms (5 DB calls) App DB connections: 3/15 Jetty threads: 8/50 (5 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:15,029 DEBUG middleware.log :: [32mGET /api/collection/root 200 1071ms (3 DB calls) App DB connections: 3/15 Jetty threads: 8/50 (5 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:15,038 WARN queries.schema :: Ignoring invalid Card result_metadata
2025-12-06 08:40:15,655 DEBUG middleware.log :: [32mGET /api/setting/version-info 200 10ms (0 DB calls) App DB connections: 6/15 Jetty threads: 8/50 (7 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:16,166 DEBUG middleware.log :: [32mGET /api/activity/popular_items 200 2192ms (10 DB calls) App DB connections: 4/15 Jetty threads: 8/50 (7 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:16,166 DEBUG middleware.log :: [32mGET /api/database 200 513ms (3 DB calls) App DB connections: 4/15 Jetty threads: 8/50 (7 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:16,171 DEBUG middleware.log :: [32mGET /api/search 200 2241ms (7 DB calls) App DB connections: 4/15 Jetty threads: 8/50 (7 idle, 0 queued) (125 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:16,209 DEBUG middleware.log :: [32mGET /api/activity/recents 200 2287ms (23 DB calls) App DB connections: 1/15 Jetty threads: 5/50 (9 idle, 0 queued) (128 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:36,790 DEBUG middleware.log :: [32mGET /api/dashboard/37 200 3885ms (10 DB calls) App DB connections: 0/15 Jetty threads: 7/50 (5 idle, 0 queued) (127 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:36,802 DEBUG middleware.log :: [32mGET /api/dashboard/37/query_metadata 200 3916ms (35 DB calls) App DB connections: 1/15 Jetty threads: 7/50 (5 idle, 0 queued) (127 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:37,296 DEBUG middleware.log :: [32mGET /api/pulse/form_input 200 11ms (1 DB calls) App DB connections: 15/15 Jetty threads: 14/50 (3 idle, 0 queued) (129 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:40:38,346 DEBUG middleware.log :: [32mGET /api/collection/6 200 1072ms (6 DB calls) App DB connections: 12/15 Jetty threads: 19/50 (1 idle, 0 queued) (133 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:41:01,023 DEBUG middleware.log :: [32mGET /api/collection/5 200 12236ms (4 DB calls) App DB connections: 15/15 Jetty threads: 19/50 (1 idle, 0 queued) (134 total active threads) Queries in flight: 0 (0 queued) {:metabase-user-id 1}[0m
2025-12-06 08:41:18,082 INFO task.sync-databases :: Starting sync task for Database 3. {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:19,608 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 3.8 s
2025-12-06 08:41:20,215 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 4.4 s
2025-12-06 08:41:21,088 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 5.3 s
2025-12-06 08:41:21,107 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 6.7 s
2025-12-06 08:41:21,534 INFO sync.util :: [35mSTARTING: Sync metadata for postgres Database 3 ''JDP Data'' (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:21,953 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-referenced/resolve-referenced-card-resources took 2.3 s
2025-12-06 08:41:22,415 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.fetch-source-query/resolve-source-cards took 5.6 s
2025-12-06 08:41:22,880 INFO sync.describe-database :: Skipping schema 'private' because it does not match the current schema filtering settings {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:22,888 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-referenced/resolve-referenced-card-resources took 1.8 s
2025-12-06 08:41:22,889 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-referenced/resolve-referenced-card-resources took 1.8 s
2025-12-06 08:41:24,181 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.add-remaps/add-remapped-columns took 1.3 s
2025-12-06 08:41:24,645 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-referenced/resolve-referenced-card-resources took 2.6 s
2025-12-06 08:41:25,648 INFO sync.util :: [35mSTARTING: step ''sync-dbms-version'' for postgres Database 3 ''JDP Data'' (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:25,657 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.auto-bucket-datetimes/auto-bucket-datetimes took 1.0 s
2025-12-06 08:41:26,110 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.add-remaps/add-remapped-columns took 1.5 s
2025-12-06 08:41:26,528 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.wrap-value-literals/wrap-value-literals took 2.8 s
2025-12-06 08:41:26,911 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.add-remaps/add-remapped-columns took 1.3 s
2025-12-06 08:41:26,917 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.add-remaps/add-remapped-columns took 1.3 s
2025-12-06 08:41:28,906 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.resolve-fields/resolve-fields took 2.0 s
2025-12-06 08:41:30,443 INFO sync.util :: [35mFINISHED: step ''sync-dbms-version'' for postgres Database 3 ''JDP Data'' (4.8 s) (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:30,444 INFO sync.util :: [35mSTARTING: step ''sync-timezone'' for postgres Database 3 ''JDP Data'' (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:31,050 WARN query-processor.preprocess :: Slow middleware: #'metabase.query-processor.middleware.optimize-temporal-filters/optimize-temporal-filters took 2.1 s
2025-12-06 08:41:34,100 INFO middleware.cache :: Query 2e4bd090 took 7.6 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:34,100 INFO middleware.cache :: Caching results for next time for query with hash "2e4bd090". 💾
2025-12-06 08:41:34,631 INFO middleware.cache :: Query 06d95073 took 6.6 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:34,632 INFO middleware.cache :: Caching results for next time for query with hash "06d95073". 💾
2025-12-06 08:41:36,509 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/286/card/154/query 202 [ASYNC: completed] 59234ms (19 DB calls) App DB connections: 4/15 Jetty threads: 7/50 (11 idle, 0 queued) (142 total active threads) Queries in flight: 12 (0 queued); postgres DB 3 connections: 1/2 (0 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:36,528 INFO sync-metadata.sync-timezone :: :postgres database 3 default timezone is "GMT" {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:36,533 INFO middleware.cache :: Query 49946bf7 took 4.3 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:36,533 INFO middleware.cache :: Caching results for next time for query with hash "49946bf7". 💾
2025-12-06 08:41:37,035 INFO middleware.cache :: Query 9ff63751 took 3.4 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:37,053 INFO middleware.cache :: Caching results for next time for query with hash "9ff63751". 💾
2025-12-06 08:41:37,531 INFO middleware.cache :: Query d96004a2 took 3.9 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:37,536 INFO middleware.cache :: Caching results for next time for query with hash "d96004a2". 💾
2025-12-06 08:41:37,537 INFO middleware.cache :: Query 54f5b285 took 7.1 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:37,538 INFO middleware.cache :: Caching results for next time for query with hash "54f5b285". 💾
2025-12-06 08:41:37,546 INFO sync.util :: [35mFINISHED: step ''sync-timezone'' for postgres Database 3 ''JDP Data'' (7.1 s) (free: 0.00G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:37,546 INFO sync.util :: [35mSTARTING: step ''sync-tables'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:37,554 INFO middleware.cache :: Query 0b2d2418 took 2.0 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:37,554 INFO middleware.cache :: Caching results for next time for query with hash "0b2d2418". 💾
2025-12-06 08:41:37,561 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/212/card/82/query 202 [ASYNC: completed] 60259ms (21 DB calls) App DB connections: 7/15 Jetty threads: 6/50 (13 idle, 0 queued) (141 total active threads) Queries in flight: 11 (0 queued); postgres DB 3 connections: 1/2 (0 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:38,101 INFO middleware.cache :: Query 4b721321 took 7.7 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:38,101 INFO middleware.cache :: Caching results for next time for query with hash "4b721321". 💾
2025-12-06 08:41:38,106 INFO middleware.cache :: Query 0c31b6bd took 3.0 s to run; minimum for cache eligibility is 0.0 ns; eligible
2025-12-06 08:41:38,106 INFO middleware.cache :: Caching results for next time for query with hash "0c31b6bd". 💾
2025-12-06 08:41:38,598 INFO middleware.cache :: Query f78ef8e7 took 4.5 s to run; minimum for cache eligibility is 0.0 ns; not eligible
2025-12-06 08:41:38,599 INFO middleware.cache :: Query af35fb90 took 6.4 s to run; minimum for cache eligibility is 0.0 ns; not eligible
2025-12-06 08:41:38,612 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/226/card/84/query 202 [ASYNC: canceled] 60755ms (15 DB calls) App DB connections: 12/15 Jetty threads: 5/50 (15 idle, 0 queued) (141 total active threads) Queries in flight: 11 (0 queued); postgres DB 3 connections: 2/2 (4 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:39,094 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/223/card/129/query 202 [ASYNC: canceled] 61266ms (13 DB calls) App DB connections: 11/15 Jetty threads: 7/50 (13 idle, 0 queued) (141 total active threads) Queries in flight: 9 (0 queued); postgres DB 3 connections: 6/6 (4 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:39,099 INFO middleware.cache :: Query 74248996 took 4.5 s to run; minimum for cache eligibility is 0.0 ns; not eligible
[585900.765s][warning][gc,alloc] MetabaseScheduler_Worker-2: Retried waiting for GCLocker too often allocating 338 words
2025-12-06 08:41:43,598 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/285/card/153/query 202 [ASYNC: canceled] 62824ms (18 DB calls) App DB connections: 15/15 Jetty threads: 6/50 (14 idle, 0 queued) (141 total active threads) Queries in flight: 8 (0 queued); postgres DB 3 connections: 2/2 (2 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:43,600 INFO sync-metadata.tables :: Updating table metadata for Table 52 ''public.guestline_payments'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:43,600 INFO sync-metadata.tables :: Updating table metadata for Table 68 ''public.social_posts'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:43,600 INFO sync-metadata.tables :: Updating table metadata for Table 53 ''public.guestline_revenue'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:43,600 INFO sync-metadata.tables :: Updating table metadata for Table 66 ''public.guestline_roompicks_state'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:43,601 INFO sync-metadata.tables :: :estimated_row_count of Table 66 ''public.guestline_roompicks_state'' changed from 169388 to 169389 {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:43,991 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/267/card/146/query 202 [ASYNC: completed] 65854ms (16 DB calls) App DB connections: 10/15 Jetty threads: 5/50 (15 idle, 0 queued) (141 total active threads) Queries in flight: 6 (0 queued); postgres DB 3 connections: 2/2 (0 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:43,996 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/217/card/127/query 202 [ASYNC: canceled] 65323ms (14 DB calls) App DB connections: 12/15 Jetty threads: 6/50 (14 idle, 0 queued) (141 total active threads) Queries in flight: 5 (0 queued); postgres DB 3 connections: 6/6 (3 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:43,997 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/221/card/128/query 202 [ASYNC: canceled] 66715ms (18 DB calls) App DB connections: 12/15 Jetty threads: 6/50 (14 idle, 0 queued) (141 total active threads) Queries in flight: 5 (0 queued); postgres DB 3 connections: 6/6 (5 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:45,322 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/213/card/113/query 202 [ASYNC: completed] 67505ms (18 DB calls) App DB connections: 12/15 Jetty threads: 9/50 (11 idle, 0 queued) (141 total active threads) Queries in flight: 2 (0 queued); postgres DB 3 connections: 5/5 (3 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:45,324 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/215/card/114/query 202 [ASYNC: completed] 67474ms (16 DB calls) App DB connections: 13/15 Jetty threads: 9/50 (11 idle, 0 queued) (141 total active threads) Queries in flight: 2 (0 queued); postgres DB 3 connections: 3/4 (4 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:45,329 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/268/card/147/query 202 [ASYNC: completed] 68045ms (16 DB calls) App DB connections: 14/15 Jetty threads: 9/50 (11 idle, 0 queued) (141 total active threads) Queries in flight: 2 (0 queued); postgres DB 3 connections: 2/2 (1 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:50,399 INFO sync-metadata.tables :: Updating table metadata for Table 65 ''public.review_sentiment'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,404 INFO sync-metadata.tables :: Updating table metadata for Table 57 ''public.tem_energy_usage'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,404 INFO sync-metadata.tables :: Updating table metadata for Table 60 ''public.monthly_costs'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,404 INFO sync-metadata.tables :: Updating table metadata for Table 54 ''public.guestline_cfwd'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,404 INFO sync-metadata.tables :: Updating table metadata for Table 67 ''public.guestline_contacts_state'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,404 INFO sync-metadata.tables :: :estimated_row_count of Table 67 ''public.guestline_contacts_state'' changed from 116388 to 116389 {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,859 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/354/card/210/query 202 [ASYNC: completed] 73019ms (27 DB calls) App DB connections: 10/15 Jetty threads: 6/50 (14 idle, 0 queued) (141 total active threads) Queries in flight: 1 (0 queued); postgres DB 3 connections: 7/7 (5 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:50,871 INFO sync-metadata.tables :: Updating table metadata for Table 55 ''public.guestline_statistics'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,871 INFO sync-metadata.tables :: Updating table metadata for Table 64 ''public.reviews'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,872 INFO sync-metadata.tables :: Updating table metadata for Table 61 ''public.gas_usage'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,872 INFO sync-metadata.tables :: Updating table metadata for Table 58 ''public.master_data'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,872 INFO sync-metadata.tables :: Updating table metadata for Table 63 ''public.manual_monthly_data'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:50,872 INFO sync-metadata.tables :: Updating table metadata for Table 115 ''public.staff_portal_news'' {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:51,738 INFO middleware.exceptions :: Request canceled before finishing.
2025-12-06 08:41:51,748 INFO sync.util :: [35mFINISHED: step ''sync-tables'' for postgres Database 3 ''JDP Data'' (14.2 s) (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:51,748 INFO sync.util :: [35mSTARTING: step ''sync-fields'' for postgres Database 3 ''JDP Data'' (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:51,763 INFO sync-metadata.fields :: Fetching field metadata for JDP Data.public {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:52,255 ERROR middleware.catch-exceptions :: Error processing query: ERROR: canceling statement due to user request
{:database_id 3,
:parameterized true,
:started_at #t "2025-12-06T08:41:13.933039585Z[GMT]",
:via
[{:status :failed,
:class clojure.lang.ExceptionInfo,
:error "Error executing query: ERROR: canceling statement due to user request",
:stacktrace
["--> driver.sql_jdbc.execute$execute_reducible_query$fn__95333$fn__95334.invoke(execute.clj:770)"
"driver.sql_jdbc.execute$execute_reducible_query$fn__95333.invoke(execute.clj:767)"
"driver.sql_jdbc.execute$fn__95108$fn__95109.invoke(execute.clj:422)"
"driver.sql_jdbc.execute$do_with_resolved_connection.invokeStatic(execute.clj:347)"
"driver.sql_jdbc.execute$do_with_resolved_connection.invoke(execute.clj:327)"
"driver.sql_jdbc.execute$fn__95108.invokeStatic(execute.clj:416)"
"driver.sql_jdbc.execute$fn__95108.invoke(execute.clj:414)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:760)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:749)"
"driver.sql_jdbc$fn__98001.invokeStatic(sql_jdbc.clj:87)"
"driver.sql_jdbc$fn__98001.invoke(sql_jdbc.clj:85)"
"query_processor.pipeline$_STAR_execute_STAR_.invokeStatic(pipeline.clj:59)"
"query_processor.pipeline$_STAR_execute_STAR_.invoke(pipeline.clj:44)"
"query_processor.pipeline$_STAR_run_STAR_.invokeStatic(pipeline.clj:119)"
"query_processor.pipeline$_STAR_run_STAR_.invoke(pipeline.clj:108)"
"query_processor.execute$run.invokeStatic(execute.clj:72)"
"query_processor.execute$run.invoke(execute.clj:62)"
"query_processor.middleware.enterprise$swap_destination_db_middleware$fn__73174.invoke(enterprise.clj:75)"
"query_processor.middleware.enterprise$apply_impersonation_postprocessing_middleware$fn__73156.invoke(enterprise.clj:50)"
"query_processor.middleware.update_used_cards$update_used_cards_BANG_$fn__75716.invoke(update_used_cards.clj:67)"
"query_processor.execute$add_native_form_to_result_metadata$fn__75756.invoke(execute.clj:27)"
"query_processor.execute$add_preprocessed_query_to_result_metadata_for_userland_query$fn__75763.invoke(execute.clj:39)"
"query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:219)"
"query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:192)"
"query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___75652.invoke(cache.clj:245)"
"query_processor.middleware.permissions$check_query_permissions$fn__72351.invoke(permissions.clj:153)"
"query_processor.middleware.enterprise$check_download_permissions_middleware$fn__73184.invoke(enterprise.clj:92)"
"query_processor.execute$execute$fn__75795.invoke(execute.clj:99)"
"query_processor.setup$do_with_qp_setup.invokeStatic(setup.clj:232)"
"query_processor.setup$do_with_qp_setup.invoke(setup.clj:223)"
"query_processor.execute$execute.invokeStatic(execute.clj:98)"
"query_processor.execute$execute.invoke(execute.clj:94)"
"query_processor$process_query_STAR__STAR_.invokeStatic(query_processor.clj:50)"
"query_processor$process_query_STAR__STAR_.invoke(query_processor.clj:45)"
"query_processor.middleware.enterprise$fn__73201$handle_audit_app_internal_queries__73202$fn__73204.invoke(enterprise.clj:124)"
"query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__73212.invoke(enterprise.clj:131)"
"query_processor.middleware.process_userland_query$process_userland_query_middleware$fn__80602.invoke(process_userland_query.clj:181)"
"query_processor.middleware.catch_exceptions$catch_exceptions$fn__80662.invoke(catch_exceptions.clj:139)"
"query_processor$process_query$fn__80702.invoke(query_processor.clj:81)"
"query_processor.setup$do_with_canceled_chan$fn__75055.invoke(setup.clj:194)"
"query_processor.setup$do_with_database_local_settings$fn__75050.invoke(setup.clj:188)"
"query_processor.setup$do_with_driver$fn__75041$fn__75042.invoke(setup.clj:173)"
"driver$do_with_driver.invokeStatic(driver.clj:54)"
"driver$do_with_driver.invoke(driver.clj:49)"
"query_processor.setup$do_with_driver$fn__75041.invoke(setup.clj:172)"
"query_processor.setup$do_with_metadata_provider$fn__75033.invoke(setup.clj:137)"
"query_processor.setup$do_with_resolved_database$fn__75025.invoke(setup.clj:125)"
"query_processor.setup$do_with_qp_setup.invokeStatic(setup.clj:240)"
"query_processor.setup$do_with_qp_setup.invoke(setup.clj:223)"
"query_processor$process_query.invokeStatic(query_processor.clj:79)"
"query_processor$process_query.invoke(query_processor.clj:72)"
"query_processor.card$process_query_for_card_default_qp.invokeStatic(card.clj:235)"
"query_processor.card$process_query_for_card_default_qp.invoke(card.clj:231)"
"query_processor.card$process_query_for_card_default_run_fn$fn__86889$fn__86890.invoke(card.clj:243)"
"query_processor.streaming$_streaming_response$fn__86073$fn__86074$fn__86075.invoke(streaming.clj:225)"
"query_processor.streaming$_streaming_response$fn__86073$fn__86074.invoke(streaming.clj:223)"
"query_processor.streaming$do_with_streaming_rff.invokeStatic(streaming.clj:214)"
"query_processor.streaming$do_with_streaming_rff.invoke(streaming.clj:201)"
"query_processor.streaming$_streaming_response$fn__86073.invoke(streaming.clj:220)"
"server.streaming_response$do_f_STAR_.invokeStatic(streaming_response.clj:83)"
"server.streaming_response$do_f_STAR_.invoke(streaming_response.clj:81)"
"server.streaming_response$do_f_async$task__83809.invoke(streaming_response.clj:98)"],
:error_type :invalid-query,
:ex-data
{:driver :postgres,
:sql
["-- Metabase:: userID: 1 queryType: MBQL queryHash: f7044fb53db6707f167b0173b3d5f01efe9921b2efa7c004186cb9b91532c7bc"
"SELECT"
" \"source\".\"display_period_start\" AS \"display_period_start\","
" \"source\".\"grain\" AS \"grain\","
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"accommodation_revenue\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"total_rooms_available\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" ) AS \"Current\","
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"accommodation_revenue\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"total_rooms_available\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" ) AS \"Previous\","
" CAST("
" ("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"accommodation_revenue\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"total_rooms_available\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" )"
" ) - ("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"accommodation_revenue\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"total_rooms_available\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" )"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"accommodation_revenue\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ) / NULLIF("
" CAST("
" SUM("
" SUM("
" CASE"
" WHEN \"source\".\"series\" = ? THEN \"source\".\"total_rooms_available\""
" ELSE 0"
" END"
" )"
" ) OVER ("
" PARTITION BY \"source\".\"grain\""
" ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC ROWS UNBOUNDED PRECEDING"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" ) AS DOUBLE PRECISION"
" ),"
" 0.0"
" ) AS \"Change\""
"FROM"
" ("
" SELECT"
" CAST(\"source\".\"display_period_start\" AS date) AS \"display_period_start\","
" \"source\".\"grain\" AS \"grain\","
" \"source\".\"series\" AS \"series\","
" \"source\".\"accommodation_revenue\" AS \"accommodation_revenue\","
" \"source\".\"total_rooms_available\" AS \"total_rooms_available\""
" FROM"
" ("
" WITH cal AS ("
" SELECT"
" *"
" FROM"
" ("
" WITH bounds AS ("
" SELECT"
" '2024-04-01' :: date AS start_dt,"
" CURRENT_DATE - INTERVAL '1 day' AS end_dt"
" ),"
" date_dim AS ("
" SELECT"
" d :: date AS dt,"
" -- ISO parts"
" to_char(d, 'IYYY') :: int AS iso_year,"
" to_char(d, 'IW') :: int AS iso_week,"
" to_char(d, 'ID') :: int AS iso_dow,"
" -- 1=Mon..7=Sun"
" date_trunc('week', d) :: date AS week_start,"
" (date_trunc('week', d) + interval '6 days') :: date AS week_end,"
" -- Calendar periods"
" date_trunc('month', d) :: date AS month_start,"
" (date_trunc('month', d) + interval '1 month - 1 day') :: date AS month_end,"
" date_trunc('quarter', d) :: date AS quarter_start,"
" ("
" date_trunc('quarter', d) + interval '3 months - 1 day'"
" ) :: date AS quarter_end,"
" date_trunc('year', d) :: date AS year_start,"
" (date_trunc('year', d) + interval '1 year - 1 day') :: date AS year_end,"
" -- ISO mapping to *same week + weekday* in the previous ISO year"
" ("
" to_char(make_date(to_char(d, 'IYYY') :: int - 1, 12, 28), 'IW') = '53'"
" ) AS prev_iso_has_w53,"
" to_char(d, 'IYYY') :: int - 1 AS prev_iso_year,"
" CASE"
" WHEN to_char(d, 'IW') = '53'"
" AND to_char(make_date(to_char(d, 'IYYY') :: int - 1, 12, 28), 'IW') != '53' THEN 52"
" ELSE to_char(d, 'IW') :: int"
" END AS prev_iso_week,"
" to_date("
" (to_char(d, 'IYYY') :: int - 1) :: text || '-' || lpad("
" ("
" CASE"
" WHEN to_char(d, 'IW') = '53'"
" AND to_char(make_date(to_char(d, 'IYYY') :: int - 1, 12, 28), 'IW') != '53' THEN 52"
" ELSE to_char(d, 'IW') :: int"
" END"
" ) :: text,"
" 2,"
" '0'"
" ) || '-' || to_char(d, 'ID'),"
" 'IYYY-IW-ID'"
" ) :: date AS prev_iso_same_weekday_dt"
" FROM"
" generate_series("
" ("
" SELECT"
" start_dt"
" FROM"
" bounds"
" ),"
" ("
" SELECT"
" end_dt"
" FROM"
" bounds"
" ),"
" interval '1 day'"
" ) s(d)"
" ) -- Expand into grains and build Current/Previous *per grain*"
" SELECT"
" *"
" FROM"
" ("
" -- ========= Day ========="
" SELECT"
" 'Day' :: text AS grain,"
" 'Current' :: text AS series,"
" dd.dt AS display_dt,"
" dd.dt AS fact_dt,"
" dd.dt AS display_period_start,"
" dd.dt AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" SELECT"
" 'Day' :: text AS grain,"
" 'Previous' :: text AS series,"
" dd.dt AS display_dt,"
" (dd.dt - interval '1 year') :: date AS fact_dt,"
" -- calendar prior year"
" dd.dt AS display_period_start,"
" dd.dt AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" -- ========= Week (ISO) ========="
" SELECT"
" 'Week' :: text AS grain,"
" 'Current' :: text AS series,"
" dd.dt AS display_dt,"
" dd.dt AS fact_dt,"
" dd.week_start AS display_period_start,"
" dd.week_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" SELECT"
" 'Week' :: text AS grain,"
" 'Previous' :: text AS series,"
" dd.dt AS display_dt,"
" dd.prev_iso_same_weekday_dt AS fact_dt,"
" -- ISO-aligned prior year"
" dd.week_start AS display_period_start,"
" dd.week_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" -- ========= Month ========="
" SELECT"
" 'Month' :: text AS grain,"
" 'Current' :: text AS series,"
" dd.dt AS display_dt,"
" dd.dt AS fact_dt,"
" dd.month_start AS display_period_start,"
" dd.month_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" SELECT"
" 'Month' :: text AS grain,"
" 'Previous' :: text AS series,"
" dd.dt AS display_dt,"
" (dd.dt - interval '1 year') :: date AS fact_dt,"
" -- calendar prior year"
" dd.month_start AS display_period_start,"
" dd.month_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" -- ========= Quarter ========="
" SELECT"
" 'Quarter' :: text AS grain,"
" 'Current' :: text AS series,"
" dd.dt AS display_dt,"
" dd.dt AS fact_dt,"
" dd.quarter_start AS display_period_start,"
" dd.quarter_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" SELECT"
" 'Quarter' :: text AS grain,"
" 'Previous' :: text AS series,"
" dd.dt AS display_dt,"
" (dd.dt - interval '1 year') :: date AS fact_dt,"
" -- calendar prior year"
" dd.quarter_start AS display_period_start,"
" dd.quarter_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" -- ========= Year ========="
" SELECT"
" 'Year' :: text AS grain,"
" 'Current' :: text AS series,"
" dd.dt AS display_dt,"
" dd.dt AS fact_dt,"
" dd.year_start AS display_period_start,"
" dd.year_end AS display_period_end"
" FROM"
" date_dim dd"
" UNION ALL"
" SELECT"
" 'Year' :: text AS grain,"
" 'Previous' :: text AS series,"
" dd.dt AS display_dt,"
" (dd.dt - interval '1 year') :: date AS fact_dt,"
" -- calendar prior year"
" dd.year_start AS display_period_start,"
" dd.year_end AS display_period_end"
" FROM"
" date_dim dd"
" ) x"
" ORDER BY"
" grain,"
" display_period_start,"
" series,"
" display_dt"
" ) cal"
" ),"
" daily AS ("
" SELECT"
" cal.grain,"
" cal.series,"
" cal.display_dt,"
" -- bind dashboard Date filter here"
" cal.fact_dt,"
" -- join facts on this"
" cal.display_period_start,"
" cal.display_period_end,"
" f.site_id,"
" f.total_revenue :: numeric AS total_revenue,"
" f.accommodation_revenue :: numeric AS accommodation_revenue,"
" f.food_revenue :: numeric AS food_revenue,"
" f.beverage_revenue :: numeric AS beverage_revenue,"
" f.other_revenue :: numeric AS other_revenue,"
" f.rooms_sold :: numeric AS rooms_sold,"
" f.rooms_available :: numeric AS rooms_available,"
" f.rooms_out_of_service :: numeric AS rooms_out_of_service,"
" f.rooms_deducted_from_stock :: numeric AS rooms_deducted_from_stock,"
" f.sleepers :: numeric AS sleepers,"
" f.deposits :: numeric AS deposits,"
" f.electricity_usage :: numeric AS electricity_usage"
" FROM"
" cal"
" LEFT JOIN public.master_data f ON f.\"dt\" = cal.fact_dt"
" ),"
" current_periods AS ("
" SELECT"
" DISTINCT grain,"
" site_id,"
" display_period_start"
" FROM"
" daily"
" WHERE"
" series = 'Current'"
" AND site_id IS NOT NULL"
" )"
" SELECT"
" d.grain,"
" d.series,"
" d.site_id,"
" d.display_dt,"
" d.fact_dt,"
" d.display_period_start,"
" d.display_period_end,"
" d.total_revenue,"
" d.accommodation_revenue,"
" d.food_revenue,"
" d.beverage_revenue,"
" d.other_revenue,"
" d.rooms_sold,"
" d.rooms_available,"
" d.rooms_out_of_service,"
" d.rooms_deducted_from_stock,"
" d.sleepers,"
" d.deposits,"
" d.electricity_usage,"
" d.food_revenue + d.beverage_revenue AS food_and_beverage_revenue,"
" d.rooms_sold + d.rooms_available + d.rooms_out_of_service AS total_rooms_available"
" FROM"
" daily d"
" WHERE"
" d.series = 'Current'"
" OR EXISTS ("
" SELECT"
" 1"
" FROM"
" current_periods cp"
" WHERE"
" cp.grain = d.grain"
" AND cp.site_id = d.site_id"
" AND cp.display_period_start = d.display_period_start"
" )"
" ORDER BY"
" d.grain,"
" d.display_period_start,"
" d.site_id,"
" d.series"
" ) AS \"source\""
" WHERE"
" (\"source\".\"site_id\" = ?)"
" AND \"source\".\"display_dt\" BETWEEN ? AND ?"
" AND (\"source\".\"grain\" = ?)"
" ) AS \"source\""
"GROUP BY"
" \"source\".\"display_period_start\","
" \"source\".\"grain\""
"ORDER BY"
" \"source\".\"grain\" ASC,"
" \"source\".\"display_period_start\" ASC"],
:params
("Current"
"Current"
"Previous"
"Previous"
"Current"
"Current"
"Previous"
"Previous"
"Previous"
"Previous"
"BEAUFORTP"
#t "2025-11-01"
#t "2025-11-30"
"Day"),
:type :invalid-query}}],
:action_id nil,
:state "57014",
:error_type :invalid-query,
:json_query
{:constraints {:max-results 10000, :max-results-bare-rows 2000},
:lib/type :mbql/query,
:lib/metadata
(metabase.lib.metadata.invocation-tracker/invocation-tracker-provider (metabase.lib.metadata.cached-provider/cached-metadata-provider (metabase.lib-be.metadata.jvm/->UncachedApplicationDatabaseMetadataProvider 3))),
:stages
[{:lib/type :mbql.stage/mbql,
:aggregation
[[:/
{:lib/uuid "535ae539-9813-40f0-b288-7f9a0aa093a7", :name "Current", :display-name "Current"}
[:cum-sum
{:lib/uuid "3ecf2956-4b0b-4d4a-955e-61d502dfd3a5"}
[:if
{:lib/uuid "73c213e1-a823-4e0f-acb0-78a3946b310a"}
[[[:=
{:lib/uuid "539366c9-6ac0-4ef9-965f-8194e9281a9c"}
[:field {:base-type :type/Text, :lib/uuid "3366898a-429b-44e5-9daf-2acd7bb75c43"} "series"]
"Current"]
[:field
{:base-type :type/Decimal, :lib/uuid "655ed274-016e-4ca8-9b6c-aff8714161ef"}
"accommodation_revenue"]]]
0]]
[:cum-sum
{:lib/uuid "0a8fb9bd-9cdc-458a-a470-cfa2ce7d28e5"}
[:if
{:lib/uuid "ef9c1bd3-6a38-411f-ac75-ed57cc1237e3"}
[[[:=
{:lib/uuid "08e139e5-39f7-4ee2-b64d-25dc88d4e3c3"}
[:field {:base-type :type/Text, :lib/uuid "6b4f45ff-ce6f-4cbf-8342-117b46b4572f"} "series"]
"Current"]
[:field
{:base-type :type/Decimal, :lib/uuid "0b60daa4-dcc0-4801-9129-0216dc7ae965"}
"total_rooms_available"]]]
0]]]
[:/
{:lib/uuid "41769843-150f-482f-8210-844b5eee5ad6", :name "Previous", :display-name "Previous"}
[:cum-sum
{:lib/uuid "6c723363-432f-481d-89c2-236405cef850"}
[:if
{:lib/uuid "12bf1e82-d570-4f4d-842e-eeb1a8846c78"}
[[[:=
{:lib/uuid "e24365e4-fa7b-4b5e-bcd8-b4c1f53f147f"}
[:field {:base-type :type/Text, :lib/uuid "4d6ccfe2-db12-4f44-858e-0d061f5a5a6e"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "9aeb07ab-868a-4508-8991-666f05bf4520"}
"accommodation_revenue"]]]
0]]
[:cum-sum
{:lib/uuid "768eed1e-465d-48ad-8bdc-acbd3057e870"}
[:if
{:lib/uuid "2275f69f-5505-4e67-a8c2-28688a41d420"}
[[[:=
{:lib/uuid "ce4520ff-aef8-4dcd-b5a9-46fff1af2de6"}
[:field {:base-type :type/Text, :lib/uuid "227e18c5-097e-4980-b144-8f3879990a5f"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "c20a0718-3c43-4fc8-aac9-8cfc11732217"}
"total_rooms_available"]]]
0]]]
[:/
{:lib/uuid "0f5f4cc1-68e9-43b0-9b7b-085df8068f16", :name "Change", :display-name "Change"}
[:-
{:lib/uuid "9e8c651f-f9d8-44b1-bbad-f079e59c5fee"}
[:/
{:lib/uuid "7e8c4af1-f902-4b18-9600-d13fd17c07fd"}
[:cum-sum
{:lib/uuid "b809baa3-4cff-418a-8f6f-37239c23f2d7"}
[:if
{:lib/uuid "8a9f89fb-4bbd-4812-a01c-641fa1b6712c"}
[[[:=
{:lib/uuid "8c77630c-784d-445c-8685-abe1707fa831"}
[:field {:base-type :type/Text, :lib/uuid "18f3acbe-4411-4a78-ad6d-a0e9f996705a"} "series"]
"Current"]
[:field
{:base-type :type/Decimal, :lib/uuid "ecdf36cc-6600-42e7-b025-2b2300fb4a5d"}
"accommodation_revenue"]]]
0]]
[:cum-sum
{:lib/uuid "434704ea-081f-4124-aefe-fa68d47577cb"}
[:if
{:lib/uuid "8f485d25-fbfe-4feb-ac7c-5b78ee0f8fc1"}
[[[:=
{:lib/uuid "2792e236-7710-4912-b8d4-314d5bad414e"}
[:field {:base-type :type/Text, :lib/uuid "9606913a-7068-483a-92a0-a4316f507e9a"} "series"]
"Current"]
[:field
{:base-type :type/Decimal, :lib/uuid "6296d2b0-fbeb-40e6-9642-401351186e11"}
"total_rooms_available"]]]
0]]]
[:/
{:lib/uuid "e1892797-fbb2-46b3-b04e-8dee69935d87"}
[:cum-sum
{:lib/uuid "e09530c2-2223-4036-8006-a1866463fd07"}
[:if
{:lib/uuid "9bf7deac-56fc-41b5-9305-a6d622581567"}
[[[:=
{:lib/uuid "879798e2-6bc2-4fff-b3b0-6c817d2526c7"}
[:field {:base-type :type/Text, :lib/uuid "7aac86cd-1735-4728-9570-5671a6b6dec8"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "6e0f38cd-736c-4e58-aca9-3d40d141873f"}
"accommodation_revenue"]]]
0]]
[:cum-sum
{:lib/uuid "59f419ce-16f2-443a-a94e-e03c8d67e72d"}
[:if
{:lib/uuid "a2593be0-cdf8-4d40-8901-9f2c2d893215"}
[[[:=
{:lib/uuid "8d2d1b7b-bf98-483d-af58-de385a97adb9"}
[:field {:base-type :type/Text, :lib/uuid "0d13135d-4c95-43dc-8651-6b59b172842f"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "9bcd0eae-5d61-49f7-8d50-b76841c25c5d"}
"total_rooms_available"]]]
0]]]]
[:/
{:lib/uuid "7248db13-bd0f-4f22-800f-a4250308a73c"}
[:cum-sum
{:lib/uuid "b651eaa9-677e-4064-8513-a6f078946cac"}
[:if
{:lib/uuid "36ae0914-2f94-4a74-ae7c-763a88b611cb"}
[[[:=
{:lib/uuid "3227179d-9f66-4939-8f26-f28543534550"}
[:field {:base-type :type/Text, :lib/uuid "b790d144-04e8-4f77-b285-d8773187509a"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "d41799cc-2a5d-4419-9ca1-57caddd173e5"}
"accommodation_revenue"]]]
0]]
[:cum-sum
{:lib/uuid "4a5c71a3-d7d3-4852-99e1-e58783683c83"}
[:if
{:lib/uuid "74927866-0daf-4e8f-9735-ce5d651723b7"}
[[[:=
{:lib/uuid "6b3895f1-393e-4333-b363-f5768464dce4"}
[:field {:base-type :type/Text, :lib/uuid "5ad96b8b-a677-4c7a-b747-1d8f9278e858"} "series"]
"Previous"]
[:field
{:base-type :type/Decimal, :lib/uuid "c7a0d203-0629-4c64-b750-dc1284990aa0"}
"total_rooms_available"]]]
0]]]]],
:breakout
[[:field {:base-type :type/Date, :lib/uuid "fa932888-1262-4156-9327-cead181721db"} "display_period_start"]
[:field {:base-type :type/Text, :lib/uuid "a94302d4-e5c2-46d7-a152-26880a8c0bf4"} "grain"]],
:source-card 109}],
:middleware {:js-int-to-string? true, :ignore-cached-results? false, :userland-query? true},
:cache-strategy
{:multiplier 60,
:min_duration_ms 1000,
:type :ttl,
:invalidated-at #t "2025-10-29T23:47:28.922751Z",
:avg-execution-ms 0},
:viz-settings
{:scalar.comparisons
[{:id "6104434b-6f75-608b-3a7d-0c576536a482", :type "anotherColumn", :label "Previous Year", :column "Previous"}],
:column_settings {"[\"name\",\"Current\"]" {:number_style "currency"}}},
:lib.convert/converted? true,
:database 3,
:parameters
[{:type :string/=,
:value ["BEAUFORTP"],
:id "75482a93",
:target [:dimension [:field "site_id" {:base-type :type/Text}] {:stage-number 0}]}
{:type :date/all-options,
:value "2025-11-01~2025-11-30",
:id "76eeb7de",
:target [:dimension [:field "display_dt" {:base-type :type/Date}] {:stage-number 0}]}
{:type :string/=,
:value ["Day"],
:id "d16405ff",
:target [:dimension [:field "grain" {:base-type :type/Text}] {:stage-number 0}]}]},
:status :failed,
:class org.postgresql.util.PSQLException,
:stacktrace
["org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2734)"
"org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2421)"
"org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:372)"
"org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:518)"
"org.postgresql.jdbc.PgStatement.execute(PgStatement.java:435)"
"org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:196)"
"org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:139)"
"com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:1185)"
"--> driver.sql_jdbc.execute$fn__95237.invokeStatic(execute.clj:578)"
"driver.sql_jdbc.execute$fn__95237.invoke(execute.clj:576)"
"driver.postgres$fn__98510.invokeStatic(postgres.clj:1019)"
"driver.postgres$fn__98510.invoke(postgres.clj:1015)"
"driver.sql_jdbc.execute$execute_statement_or_prepared_statement_BANG_.invokeStatic(execute.clj:591)"
"driver.sql_jdbc.execute$execute_statement_or_prepared_statement_BANG_.invoke(execute.clj:587)"
"driver.sql_jdbc.execute$execute_reducible_query$fn__95333$fn__95334.invoke(execute.clj:768)"
"driver.sql_jdbc.execute$execute_reducible_query$fn__95333.invoke(execute.clj:767)"
"driver.sql_jdbc.execute$fn__95108$fn__95109.invoke(execute.clj:422)"
"driver.sql_jdbc.execute$do_with_resolved_connection.invokeStatic(execute.clj:347)"
"driver.sql_jdbc.execute$do_with_resolved_connection.invoke(execute.clj:327)"
"driver.sql_jdbc.execute$fn__95108.invokeStatic(execute.clj:416)"
"driver.sql_jdbc.execute$fn__95108.invoke(execute.clj:414)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:760)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:749)"
"driver.sql_jdbc$fn__98001.invokeStatic(sql_jdbc.clj:87)"
"driver.sql_jdbc$fn__98001.invoke(sql_jdbc.clj:85)"
"query_processor.pipeline$_STAR_execute_STAR_.invokeStatic(pipeline.clj:59)"
"query_processor.pipeline$_STAR_execute_STAR_.invoke(pipeline.clj:44)"
"query_processor.pipeline$_STAR_run_STAR_.invokeStatic(pipeline.clj:119)"
"query_processor.pipeline$_STAR_run_STAR_.invoke(pipeline.clj:108)"
"query_processor.execute$run.invokeStatic(execute.clj:72)"
"query_processor.execute$run.invoke(execute.clj:62)"
"query_processor.middleware.enterprise$swap_destination_db_middleware$fn__73174.invoke(enterprise.clj:75)"
"query_processor.middleware.enterprise$apply_impersonation_postprocessing_middleware$fn__73156.invoke(enterprise.clj:50)"
"query_processor.middleware.update_used_cards$update_used_cards_BANG_$fn__75716.invoke(update_used_cards.clj:67)"
"query_processor.execute$add_native_form_to_result_metadata$fn__75756.invoke(execute.clj:27)"
"query_processor.execute$add_preprocessed_query_to_result_metadata_for_userland_query$fn__75763.invoke(execute.clj:39)"
"query_processor.middleware.cache$run_query_with_cache.invokeStatic(cache.clj:219)"
"query_processor.middleware.cache$run_query_with_cache.invoke(cache.clj:192)"
"query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___75652.invoke(cache.clj:245)"
"query_processor.middleware.permissions$check_query_permissions$fn__72351.invoke(permissions.clj:153)"
"query_processor.middleware.enterprise$check_download_permissions_middleware$fn__73184.invoke(enterprise.clj:92)"
"query_processor.execute$execute$fn__75795.invoke(execute.clj:99)"
"query_processor.setup$do_with_qp_setup.invokeStatic(setup.clj:232)"
"query_processor.setup$do_with_qp_setup.invoke(setup.clj:223)"
"query_processor.execute$execute.invokeStatic(execute.clj:98)"
"query_processor.execute$execute.invoke(execute.clj:94)"
"query_processor$process_query_STAR__STAR_.invokeStatic(query_processor.clj:50)"
"query_processor$process_query_STAR__STAR_.invoke(query_processor.clj:45)"
"query_processor.middleware.enterprise$fn__73201$handle_audit_app_internal_queries__73202$fn__73204.invoke(enterprise.clj:124)"
"query_processor.middleware.enterprise$handle_audit_app_internal_queries_middleware$fn__73212.invoke(enterprise.clj:131)"
"query_processor.middleware.process_userland_query$process_userland_query_middleware$fn__80602.invoke(process_userland_query.clj:181)"
"query_processor.middleware.catch_exceptions$catch_exceptions$fn__80662.invoke(catch_exceptions.clj:139)"
"query_processor$process_query$fn__80702.invoke(query_processor.clj:81)"
"query_processor.setup$do_with_canceled_chan$fn__75055.invoke(setup.clj:194)"
"query_processor.setup$do_with_database_local_settings$fn__75050.invoke(setup.clj:188)"
"query_processor.setup$do_with_driver$fn__75041$fn__75042.invoke(setup.clj:173)"
"driver$do_with_driver.invokeStatic(driver.clj:54)"
"driver$do_with_driver.invoke(driver.clj:49)"
"query_processor.setup$do_with_driver$fn__75041.invoke(setup.clj:172)"
"query_processor.setup$do_with_metadata_provider$fn__75033.invoke(setup.clj:137)"
"query_processor.setup$do_with_resolved_database$fn__75025.invoke(setup.clj:125)"
"query_processor.setup$do_with_qp_setup.invokeStatic(setup.clj:240)"
"query_processor.setup$do_with_qp_setup.invoke(setup.clj:223)"
"query_processor$process_query.invokeStatic(query_processor.clj:79)"
"query_processor$process_query.invoke(query_processor.clj:72)"
"query_processor.card$process_query_for_card_default_qp.invokeStatic(card.clj:235)"
"query_processor.card$process_query_for_card_default_qp.invoke(card.clj:231)"
"query_processor.card$process_query_for_card_default_run_fn$fn__86889$fn__86890.invoke(card.clj:243)"
"query_processor.streaming$_streaming_response$fn__86073$fn__86074$fn__86075.invoke(streaming.clj:225)"
"query_processor.streaming$_streaming_response$fn__86073$fn__86074.invoke(streaming.clj:223)"
"query_processor.streaming$do_with_streaming_rff.invokeStatic(streaming.clj:214)"
"query_processor.streaming$do_with_streaming_rff.invoke(streaming.clj:201)"
"query_processor.streaming$_streaming_response$fn__86073.invoke(streaming.clj:220)"
"server.streaming_response$do_f_STAR_.invokeStatic(streaming_response.clj:83)"
"server.streaming_response$do_f_STAR_.invoke(streaming_response.clj:81)"
"server.streaming_response$do_f_async$task__83809.invoke(streaming_response.clj:98)"],
:card_id 126,
:context :dashboard,
:error "ERROR: canceling statement due to user request",
:row_count 0,
:running_time 0,
:data {:rows [], :cols []}}
2025-12-06 08:41:52,259 DEBUG middleware.log :: [32mPOST /api/dashboard/37/dashcard/214/card/126/query 202 [ASYNC: canceled] 74981ms (15 DB calls) App DB connections: 1/15 Jetty threads: 4/50 (15 idle, 0 queued) (141 total active threads) Queries in flight: 0 (0 queued); postgres DB 3 connections: 8/8 (5 threads blocked) {:metabase-user-id 1}[0m
2025-12-06 08:41:53,724 INFO sync.util :: [35mFINISHED: step ''sync-fields'' for postgres Database 3 ''JDP Data'' (2.0 s) (free: 0.00G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,724 INFO sync.util :: [35mSTARTING: step ''sync-fks'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,737 INFO sync.util :: [35mFINISHED: step ''sync-fks'' for postgres Database 3 ''JDP Data'' (12.1 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,737 INFO sync.util :: [35mSTARTING: step ''sync-indexes'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,741 INFO sync.util :: [35mFINISHED: step ''sync-indexes'' for postgres Database 3 ''JDP Data'' (3.7 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,741 INFO sync.util :: [35mSTARTING: step ''sync-metabase-metadata'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,744 INFO sync.util :: [35mFINISHED: step ''sync-metabase-metadata'' for postgres Database 3 ''JDP Data'' (3.4 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,746 INFO sync.util :: [35mFINISHED: Sync metadata for postgres Database 3 ''JDP Data'' (32.2 s) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,747 INFO sync.util :: [35mSTARTING: Analyze data for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:53,749 INFO sync.util :: [35mSTARTING: step ''fingerprint-fields'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,141 INFO sync.analyze :: [34mfingerprint-fields Analyzed [*****·············································] 😢 11% Table 55 ''public.guestline_statistics''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,147 INFO sync.analyze :: [34mfingerprint-fields Analyzed [**********········································] 😒 22% Table 60 ''public.monthly_costs''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,150 INFO sync.analyze :: [34mfingerprint-fields Analyzed [****************··································] 😕 33% Table 57 ''public.tem_energy_usage''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,154 INFO sync.util :: [35mFINISHED: step ''fingerprint-fields'' for postgres Database 3 ''JDP Data'' (404.9 ms) (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,154 INFO sync.util :: [35mSTARTING: step ''classify-fields'' for postgres Database 3 ''JDP Data'' (free: 0.01G, total: 0.81G, ratio: 0.01)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,161 INFO sync.analyze :: [34mclassify-fields Analyzed [*********************·····························] 😐 43% Table 55 ''public.guestline_statistics''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,164 INFO sync.analyze :: [34mclassify-fields Analyzed [***************************·······················] 😌 54% Table 60 ''public.monthly_costs''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,166 INFO sync.analyze :: [34mclassify-fields Analyzed [********************************··················] 😏 65% Table 57 ''public.tem_energy_usage''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,168 INFO sync.util :: [35mFINISHED: step ''classify-fields'' for postgres Database 3 ''JDP Data'' (13.6 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,168 INFO sync.util :: [35mSTARTING: step ''classify-tables'' for postgres Database 3 ''JDP Data'' (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,173 INFO sync.analyze :: [34mclassify-tables Analyzed [**************************************············] 😋 76% Table 55 ''public.guestline_statistics''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,173 INFO sync.analyze :: [34mclassify-tables Analyzed [*******************************************·······] 😊 87% Table 60 ''public.monthly_costs''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,174 INFO sync.analyze :: [34mclassify-tables Analyzed [************************************************··] 😎 98% Table 57 ''public.tem_energy_usage''[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,175 INFO sync.util :: [35mFINISHED: step ''classify-tables'' for postgres Database 3 ''JDP Data'' (7.1 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
2025-12-06 08:41:54,181 INFO sync.util :: [35mFINISHED: Analyze data for postgres Database 3 ''JDP Data'' (434.1 ms) (free: 0.00G, total: 0.81G, ratio: 0.00)[0m {mb-quartz-job-type=SyncAndAnalyzeDatabase}
The memory usage in the docker container itself is 50% though - so that's worth noting. CPU usage doesn't spike until requests are made - at idle it's around 15-20%
This sounds very similar to problems we are having. We haven't seen the OOM reproduce since we increased to Xmx6g so you might consider that as a workaround, but pretty sure the 4 million PGStream Tuple objects stored in threadLocals we found with HeapDumpOnOutOfMemoryError is a bug. However we're still having a problem where "Queries in flight" slowly leaks over time also causing metabase to grind to unusably slow, so we've been restarting at least that often which might be papering over the OOM inevitably occurring even with Xmx6g https://github.com/metabase/metabase/issues/65668
@shivampaw and @ambro-devprox since you're on 57 can you upgrade to 57.6.2 and check if this still happens?
@Tony-metabase i've upgraded - will let you know if it occurs again in the next week or so