# Slow Query Analysis — `server-slow9-sep.log` **Window:** 2026-09-08 19:29:46 → 2026-09-09 19:05:05 server local time (**23.6 hours**) **File size:** 6.7 MB · 9,783 queries · 21 distinct patterns This log starts at the same moment as `server-slow-new.log` and extends it to a full day. Everything in the previous report is contained here, now with 22 more hours of context — and that context changes one of my earlier conclusions. --- ## Summary | | | |---|---| | Queries logged | 9,783 (**all ≥ 10 s**) | | Total execution time | **5,607,801 s = 1,558 hours** | | Wall-clock window | 23.6 hours | | **Average concurrency** | **65.9 threads, sustained, all day** | | **Peak concurrency** | **218** | | Slowest single query | **6,406 s (1 h 47 m)** | | Queries running over 1 hour | **229** | | Rows examined | 5,866,969,992 | | Rows returned | 788,773 | | Schemas affected | 1 (`excellen_vip3`) | The server performed **1,558 hours of database work in a 24-hour day** — 66× more than wall-clock time permits. Nothing has been fixed since the last report. --- ## 1. Correction to my previous analysis In the last report I wrote that the load "is recovering, slowly" and that the backlog was draining, based on concurrency falling from 175 to 1.7 across a 1.8-hour window. **That was wrong, and I had too little data to say it.** With a full day visible, that decline is just an ordinary daily trough. Load climbed straight back and peaked *higher* than anything in the previous file. | Local hour | Approx. US Eastern | New queries | Avg concurrency | |---|---|---|---| | 08 19:00 | 03:00 | 439 | 89.3 | | 08 21:00 | 05:00 | 216 | **19.3** ← daily low | | 08 23:00 | 07:00 | 306 | 50.9 | | 09 01:00 | 09:00 | 361 | 68.4 | | 09 04:00 | 12:00 | 378 | 77.7 | | 09 05:00 | 13:00 | 560 | 109.9 | | **09 06:00** | **14:00** | **629** | **138.7** ← daily peak | | 09 09:00 | 17:00 | 539 | 101.9 | | 09 11:00 | 19:00 | 579 | 84.1 | | 09 14:00 | 22:00 | 483 | 74.5 | | 09 18:00 | 02:00 | 284 | 24.8 | **Concurrency never drops below 19 at any point in 24 hours.** The database is continuously saturated. What I read as recovery was the 5 AM Eastern lull. The server's local clock runs at UTC+12, but the search terms are US phone numbers (813 Tampa, 470 Atlanta, 754 Fort Lauderdale, 332 New York). Converting to US Eastern, the curve peaks at 2 PM and bottoms out at 5 AM — a textbook organic US business-hours traffic pattern. This confirms the load is **real customers, not bots**, and means you can predict the next peak: roughly 2 PM Eastern, every weekday. --- ## 2. Still one query | # | Pattern | Execs | Total time | % | Avg | Max | Exam/call | |---|---|---|---|---|---|---|---| | 1 | `cart_products` + `cart_product_images` — **levenshtein_ratio + FIND_IN_SET** | 9,531 | **5,600,935 s** | **99.88%** | 588 s | 6,406 s | 586,155 | | 2 | same query, starved variant | 3 | 2,577 s | 0.05% | 859 s | 1,554 s | **0** | | 3 | `cart_products`+`cart_brands` `COUNT(*) as total` | 152 | 2,555 s | 0.05% | 16.8 s | 39 s | 731,217 | | 4 | `cart_products`+`cart_brands` catalog listing | 45 | 665 s | 0.01% | 14.8 s | 37 s | 502,124 | | 5 | `cart_product_search` 3-table join | 8 | 336 s | 0.01% | 42 s | 102 s | 1,216,593 | | 6 | double-subquery `COUNT` on `cart_product_customfieldsx` | 20 | 281 s | 0.01% | 14 s | 28 s | 5,941,636 | | 7 | manual run by `excellentnumbers` | 1 | 98 s | — | 98 s | 98 s | 594,007 | | 8–21 | product search + catalog variants | 22 | 349 s | 0.01% | — | 36 s | 430k–1.8M | The `levenshtein_ratio` widget is 99.88% of all database time, unchanged. **Pattern 2 deserves a note.** Three executions examined **zero rows** yet took an average of 859 seconds, one of them 1,554 seconds. A query that examines nothing and still runs for 26 minutes was not doing work — it was waiting for CPU that never came. That is direct evidence of resource starvation, not slow I/O. ### Traffic driving it | | | |---|---| | Executions in 24 h | 9,531 | | Distinct product pages | 6,746 | | Distinct search strings | 6,746 | | Distinct categories | 380 | | **Effective rate** | **~4.7 product page views per minute** | Under 5 page views a minute is producing 65 permanently-saturated database threads. This remains the central point: there is no traffic level at which this query is viable. --- ## 3. New finding — the second unindexable family Now that the log is clean, a second group is visible. It is small today but it will become your top problem the moment the levenshtein widget is fixed, so fix both together. ```sql SELECT p.*, pi.* FROM cart_products p LEFT JOIN cart_product_images pi ON (p.productid = pi.imageprodid AND imageisthumb = 1) WHERE p.prodcurrentinv > 0 AND p.prodvisible = 1 AND (REPLACE(p.prodname, '-', '') LIKE '%6395555%' OR SUBSTR(p.prodcode, 6, 7) LIKE '%6395555%'); ``` This is the site's main phone-number search box, and it is unindexable three times over: 1. `REPLACE(p.prodname, '-', '')` — function wraps the column 2. `SUBSTR(p.prodcode, 6, 7)` — function wraps the column 3. `LIKE '%...%'` — leading wildcard defeats any index even without the functions Eight executions, 11–36 s each, ~594,000 rows examined per run. **The same stored-generated-column fix solves this and the levenshtein widget at once**, which makes it good value: ```sql ALTER TABLE cart_products ADD COLUMN prodname_digits VARCHAR(24) AS (REGEXP_REPLACE(prodname, '[^0-9]', '')) STORED, ADD COLUMN prodcode_digits VARCHAR(24) AS (REGEXP_REPLACE(prodcode, '[^0-9]', '')) STORED, ADD INDEX idx_prodname_digits (prodname_digits), ADD INDEX idx_prodcode_digits (prodcode_digits); ``` Then both features become `WHERE prodname_digits LIKE '6395555%'` — a prefix match that uses the index. Note that `LIKE 'x%'` uses an index while `LIKE '%x%'` cannot; if you truly need infix matching, add a FULLTEXT index or a dedicated search service rather than reintroducing the wildcard. **Third tier** (patterns 3–6, ~3,800 s/day): the catalog `COUNT(*)` and brand-listing queries scanning 731,217 rows, and the `cart_product_search` joins scanning 1.2 M. These are ordinary full scans on `cart_products` and are addressed by the composite index from the first report: ```sql ALTER TABLE cart_products ADD INDEX idx_visible_avail_inv (prodvisible, prodavailability, prodcurrentinv); ALTER TABLE cart_product_images ADD INDEX idx_prod_thumb (imageprodid, imageisthumb); ``` --- ## 4. Trend across all three collections | | Log 1+2 (29 min) | Log 3 (1.8 h) | **This log (23.6 h)** | |---|---|---|---| | Queries ≥ 10 s | 155 | 618 | **9,783** | | DB time | 144,433 s | 371,720 s | **5,607,801 s** | | Peak concurrency | 60 | 101 | **218** | | Slowest query | 5,765 s | 5,013 s | **6,406 s** | | Arrival rate of the killer query | 5.3/min | 5.8/min | **6.6/min** | | Queries over 1 hour | — | — | **229** | Every metric is flat or worse. The arrival rate has crept up slightly. **`max_statement_time` has still not been set** — a query ran for 1 hour 47 minutes in this window, and 229 queries exceeded an hour. --- ## 5. What to do Items 1 and 2 have now been the top recommendation in three consecutive reports and remain unapplied. Item 1 takes one minute and requires no code change. 1. **Set the statement timeout now.** ```sql SET GLOBAL max_statement_time = 30; ``` Add `max_statement_time=30` to `my.cnf` under `[mysqld]` so it survives a restart. This alone converts the outage into a handful of failed page loads and would have prevented all 229 hour-long queries. 2. **Cap the connection pool** so one feature cannot hold 218 threads: ```sql ALTER USER 'excellen_shaz'@'localhost' WITH MAX_USER_CONNECTIONS 30; ``` 3. **Disable the similar-numbers widget** until item 4 ships. Removes 99.88% of load immediately. 4. **Add the generated digit columns** (§3). Fixes the widget and the search box together. 5. **Replace `FIND_IN_SET(cat, prodcatids)`** with a junction table. Until this is done, category filtering forces a full scan on its own, even after the UDF is gone: ```sql CREATE TABLE cart_product_categories ( productid INT NOT NULL, categoryid INT NOT NULL, PRIMARY KEY (categoryid, productid), KEY idx_product (productid) ) ENGINE=InnoDB; ``` 6. **Add the catalog indexes** (§3, third tier) for patterns 3–6. 7. **Then re-enable `log_queries_not_using_indexes=1` with `min_examined_row_limit=1000`** for one hour and work through §3 of the first report. Those indexes — `wp_weebot_user`, `cart_sessions`, `cart_product_customfieldsx`, `cart_customers`, `wp_postmeta` — are still missing. They are absent from this log only because that setting is off, not because they were fixed. **Projected effect of items 3–5:** total database time for an identical day drops from **5,607,801 s to roughly 4,200 s** — from 1,558 hours to about 70 minutes. --- ## 6. Your two questions, answered for this file **Which queries are slow?** Twenty-one patterns exceeded 10 seconds, but the ranking is not close. The `levenshtein_ratio` + `FIND_IN_SET` product-similarity query is 99.88% of all database time (9,531 executions, 5,600,935 s). Second place is 0.05%. Every one of the 21 patterns touches `cart_products`; no other table or schema appears anywhere in this log. **Which queries have no index?** All 21 — but for two different reasons, and the distinction determines the fix: - **Cannot use an index at any cost** (needs a query or schema rewrite): the `levenshtein_ratio()` UDF, `FIND_IN_SET()` on a comma-separated column, `REPLACE()`/`SUBSTR()` wrapping columns, and `LIKE '%...%'` with a leading wildcard. - **Could use an index but doesn't have one** (add the DDL in §3): the catalog `COUNT(*)`, the brand listing, and the `cart_product_search` joins. This log cannot report on unindexed queries that ran under 10 seconds, since `log_queries_not_using_indexes` is off. The missing-index list in the first report's §3 remains outstanding and unverified.