Analyzing a 5‑Second Delay in MySQL Binlog Update Rows with a Bash Summarizer

Continuing from the previous discussion on MySQL binlog timestamps, the author revisits a case where an UPDATE statement appeared to run for five seconds. The binlog excerpt shows a #161213 10:11:30 ... Query thread_id=4900813 exec_time=5 event followed by an Update_rows event.

Two possible reasons are proposed: (1) the query itself is a slow query that scans many rows but updates only one, or (2) the statement is waiting for another transaction or lock for five seconds. The way to determine the cause is to check the slow‑query log for the thread ID on the same server; if a matching slow query is found, reason (1) applies, otherwise reason (2) is likely.

The author notes that lock‑wait time is not counted in the slow‑query log, so a five‑second exec_time can indicate waiting for a lock rather than actual execution time.

To investigate further, the article introduces a Bash script ( summarize_binlogs.sh ) that parses ROW‑mode binlogs and calculates the duration of each transaction (the period column). Running the script on a specific time window produces a list of transactions with their total row counts and periods.

Among the results, transaction Xid 83631678 shows a period of 51 seconds. Examining its binlog entries reveals that the initial Write_rows and Update_rows events occurred at 10:10:44, while subsequent Write_rows events occurred at 10:11:35, indicating a 51‑second gap where the transaction was waiting.

Further comparison shows that the record updated by transaction 83631679 (the five‑second UPDATE) is the same record modified by transaction 83631678, confirming that the latter held a lock for the entire 51‑second interval, causing the former to wait.

The conclusion is that the DBA should coordinate with developers to identify why the long‑running transaction held the lock, as the database side has been fully diagnosed.

Overall, the piece aims to help DBAs understand the role of timestamps in binlogs and how to use binlog analysis to troubleshoot seemingly mysterious delays.