# Slow Query Analysis — `server-slow-new.log`

**Window:** 2026-09-08 19:29:46 → 21:16:20 (1 h 47 m)
**File size:** 421 KB (previous pair: 79.5 MB)

---

## Summary in one line

The **logging configuration is fixed**. The **root cause is not**. This log contains 618 queries and 617 of them are the same one.

---

## 1. What changed since the last logs

| | Previous logs (29 min) | This log (107 min) |
|---|---|---|
| File size | 79.5 MB | **421 KB** |
| Queries logged | 193,752 | **618** |
| Distinct patterns | 173 | **2** |
| Fastest query in log | 0.0001 s | **10.37 s** |
| Queries under 10 s | 193,597 | **0** |

**`log_queries_not_using_indexes` has been turned off** (or `min_examined_row_limit` was raised). Nothing under 10 s appears any more, so `long_query_time=10` is now the only trigger. Log volume dropped by 99.5%, and the signal is clean.

That was the right call. But note carefully what it means: **the missing indexes from the previous report are still missing.** `wp_weebot_user`, `cart_sessions`, `cart_product_customfieldsx`, `wp_postmeta` and the rest are no longer in the log because they are no longer *reported*, not because they were fixed. Section 3 of the previous report still stands in full.

**Also: MySQL was restarted between the two logs.** `Thread_id` dropped from ~95,545 to 1,675. If that was a crash or an OOM kill rather than a planned restart, check the MySQL error log for the reason.

---

## 2. The state of things now

| Metric | Value |
|---|---|
| Queries logged | 618 |
| Distinct query patterns | 2 (functionally 1) |
| Total execution time | **371,720 s = 103 hours** |
| Wall-clock window | 1.8 hours |
| Rows examined | 367,096,529 |
| Rows returned | 3,076 |
| Average concurrency | **52 copies running at all times** |
| **Peak concurrency** | **101 simultaneous copies** |
| Median query time | 269 s |
| Slowest single query | **5,013 s (84 minutes)** |

103 hours of database work was performed inside a 1.8-hour window. The server is doing roughly **58× more work than wall-clock time allows**, which is only possible because 52–101 threads are grinding in parallel, all fighting for the same CPU and buffer pool.

---

## 3. It is one query. Only one.

```sql
SELECT p.*, pi.*
FROM cart_products p
LEFT JOIN cart_product_images pi
       ON (p.productid = pi.imageprodid AND pi.imageisthumb = 1)
WHERE p.prodvisible = 1
  AND productid != 607594
  AND FIND_IN_SET(5630, prodcatids)
  AND prodavailability = 'unreserved'
  AND prodcurrentinv != 0
  AND levenshtein_ratio('(738) 444-INFO', prodname) > 60
ORDER BY levenshtein_ratio('(738) 444-INFO', prodname) DESC
LIMIT 5;
```

| | |
|---|---|
| Executions | 617 of 618 (**100.0% of logged time**) |
| Rows examined per run | 594,007 |
| Rows returned per run | 5 |
| Efficiency | 0.0008% |
| Average | 602 s |
| Maximum | 5,013 s |

This is the identical query from the previous report. Nothing about it has been changed.

### New evidence: the query is intrinsically slow, not just a contention victim

The 618th query is interesting. It was run by a **different user** (`excellentnumbers`, not the web app's `excellen_shaz`), with hand-formatted whitespace and the exact same parameters — category 83, product 76554, `'(813) 896-2999'` — as an example from the earlier log. Someone was clearly reproducing the problem manually.

**That isolated run still took 98 seconds.**

This settles a question the previous analysis left open. The 5,000-second runtimes are caused by concurrency, but the query is *already* ~98 s when run more or less alone. Reducing load will not save you. The query itself has to change.

---

## 4. What is driving the traffic

| Signal | Value |
|---|---|
| Distinct search strings | 425 of 617 |
| Distinct excluded `productid` | 426 |
| Distinct categories queried | 188 |
| Search string shape | `(999) 999-9999` in 404 of 425 cases |

This is a "similar phone numbers" widget on the product detail page. Each distinct `productid !=` value is one product page view, so **426 page views triggered 617 executions** over 107 minutes.

**That is about 4 product page views per minute.** This is not a traffic spike, a scraper, or an attack — it is ordinary, modest, organic browsing. A single feature is converting 4 page views per minute into a server-wide outage. There is no capacity fix for this; the query is simply not viable at any traffic level.

---

## 5. Trend — it is recovering, slowly

Average concurrency per 5-minute bucket:

| Time | New queries | Avg concurrent |
|---|---|---|
| 19:29 | 42 | **175.3** |
| 19:39 | 51 | 159.6 |
| 19:49 | 28 | 65.2 |
| 20:04 | 29 | 67.4 |
| 20:19 | 32 | 70.3 |
| 20:29 | 28 | 23.6 |
| 20:44 | 16 | 12.2 |
| 21:04 | 16 | 16.5 |
| 21:14 | 4 | **1.7** |

The backlog is draining. By the end of the window the server is nearly idle. This looks like recovery from the post-restart pile-up rather than a fix taking effect — the arrival rate of new queries (~5.8/min) is essentially unchanged from the previous logs (~5.3/min). **Expect this to recur the next time traffic picks up.**

---

## 6. What to do

Priority order. Items 1 and 2 are the same recommendations as last time and have visibly not been applied.

1. **Set a statement timeout — today.** A single query ran for 84 minutes. Nothing on a web-facing database should ever do this.
   ```sql
   SET GLOBAL max_statement_time = 30;   -- MariaDB, seconds; session default
   ```
   Add `max_statement_time=30` to `my.cnf` so it survives restarts. This converts an outage into 5 failed page loads.

2. **Disable the similar-numbers widget** until it is rewritten. One config toggle in the application removes 100% of the load in this log.

3. **Rewrite the search.** The strings are phone numbers being fuzzy-matched with a UDF against 594,007 product names, twice per row. Match on normalised digits instead:
   ```sql
   ALTER TABLE cart_products
     ADD COLUMN prodname_digits VARCHAR(20)
       AS (REGEXP_REPLACE(prodname, '[^0-9]', '')) STORED,
     ADD INDEX idx_prodname_digits (prodname_digits);
   ```
   Then `WHERE prodname_digits LIKE '813896%'` for prefix matching. 594,007 rows examined becomes a handful.

4. **Replace `FIND_IN_SET(cat, prodcatids)`** with a junction table (§1 of the previous report). `FIND_IN_SET` can never use an index, so category filtering forces a full scan on its own even after the UDF is gone.

5. **Add a per-user connection cap** so one runaway feature cannot consume 101 threads:
   ```sql
   ALTER USER 'excellen_shaz'@'localhost' WITH MAX_USER_CONNECTIONS 30;
   ```

6. **Do not consider the missing-index work done.** Re-run with `log_queries_not_using_indexes=1` plus `min_examined_row_limit=1000` for one hour after the above is fixed, and work through §3 of the previous report.

7. **Check the MySQL error log** for the cause of the restart around 19:16–19:29.

**Expected result of items 1–3:** total database time for the same workload drops from 371,720 s to roughly 10 s.

---

## 7. Answering your two original questions for this file

**Which queries are slow?**
One. `cart_products` + `cart_product_images` with `levenshtein_ratio()` and `FIND_IN_SET()`. It accounts for 100.0% of logged time. There is no second-place finisher worth naming.

**Which queries have no index?**
This log cannot tell you, because `log_queries_not_using_indexes` is now off. The one query present uses no index and cannot be made to use one without the schema changes in items 3 and 4 above. For the full missing-index list, the previous report's §3 remains current — none of those indexes have been added.