Logs and counters

The silent failures need counters; the loud ones need logs that actually capture them. MySQL ships both — mostly off or easy to miss. This lesson turns on the right ones.

Deadlocks: counted forever, logged if you ask

A deadlock error flashes by in one unlucky client's logs and is gone. The server, however, counts:

A

B

debit id=1

debit id=2

credit id=2→ ⏳ waits

credit id=1← 1213 Deadlock found when trying to get lock

⏵ credit id=2→ completes

The same two opposite-order transfers as chapter 3 — one will be the victim.

A> BEGIN;
Query OK

A> UPDATE accounts SET balance = balance - 10 WHERE id = 1;
Query OK, 1 row affected

B> BEGIN;
Query OK

B> UPDATE accounts SET balance = balance - 25 WHERE id = 2;
Query OK, 1 row affected

A> UPDATE accounts SET balance = balance + 10 WHERE id = 2;
⏳ A is waiting for a lock…

B> UPDATE accounts SET balance = balance + 25 WHERE id = 1;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

⏵ A resumes:
Query OK, 1 row affected

A> COMMIT;
Query OK

The error flashed by in one client's logs. The server remembers it forever:

M> SELECT im.count - b.n >= 1 AS deadlocks_since_snapshot
   FROM information_schema.INNODB_METRICS im, deadlocks_before b
   WHERE im.name = 'lock_deadlocks'
    -- a monotonic counter — graph its rate and alert on spikes
 deadlocks_since_snapshot 
--------------------------
                        1 
(1 row)

For the full story of the LAST deadlock (both statements, both lock chains), read the LATEST DETECTED DEADLOCK section of SHOW ENGINE INNODB STATUS — or set innodb_print_all_deadlocks=ON to log every one.

Verified against MySQL 8.4.10 · Run it yourself · Scenario source

Two companions round out the counter. SHOW ENGINE INNODB STATUS keeps the full story of the most recent deadlock — both transactions, both statements, both lock chains — under its LATEST DETECTED DEADLOCK section, which makes it invaluable for diagnosing which two queries are fighting and useless for counting, since each new deadlock overwrites the last. When the counter starts climbing and you want the full population rather than the latest sample, set innodb_print_all_deadlocks = ON and MySQL writes that same report into the error log for every deadlock, not only the one you happened to catch.

The counters worth graphing

All from information_schema.INNODB_METRICS (or their SHOW GLOBAL STATUS cousins), all proven meaningful by scenarios on this site:

Counter	What it means	Proven by
lock_deadlocks	deadlocks since startup — rate, not level	the scenario above
lock_timeouts	statements that hit innodb_lock_wait_timeout (1205)	lock timeouts
trx_rseg_history_len	purge backlog — an old read view somewhere	history list health
lock_row_lock_waits / lock_row_lock_time	how often and how long writers queue	lock queues

The logs worth having

Two logs earn their keep for transaction work. The slow query log (slow_query_log, long_query_time) is the classic, and it has one under-appreciated use: a query that spent its time in a lock wait shows a long wall-clock time with trivial examine counts, and that shape means "victim of a blocker", not "needs an index". The error log is where deadlock reports land once innodb_print_all_deadlocks = ON, next to the aborted connections and wait_timeout reaps from timeout guardrails.

What no counter here catches is the silent failure: a lost update or a write skew commits cleanly and leaves every metric untouched, which is why those get caught in code rather than on a graph. For everything loud, the counters suffice — alert on the rate of lock_deadlocks, keep LATEST DETECTED DEADLOCK for the last one and innodb_print_all_deadlocks for the full population, and read a slow-log row with big time and tiny examine counts as a lock victim rather than a missing index.

Further reading

• MySQL docs: InnoDB INFORMATION_SCHEMA Metrics Table
• MySQL docs: The Slow Query Log
• The same lesson on PostgreSQL