Why Your Koa2 API Takes 900 ms and How MySQL Profiling Cuts It Down

When developing a Koa2 API I noticed a simple form‑saving endpoint took about 900 ms per request, far slower than expected.

Using MySQL profiling

MySQL provides a profiling feature to pinpoint which phase of query execution consumes time. Enable it with set profiling=1, run the statement, then view the breakdown with show profile for query 1.

MYSQL> set profiling=1
MYSQL> insert into t_test_table values ('hello')
MYSQL> show profile for query 1

The output shows most time spent in the “query end” phase. According to MySQL documentation this state occurs after the query has been processed but before the “freeing items” state, where cache cleanup happens.

The “freeing items” state frees space in the query cache, especially after UPDATE/INSERT operations.

Impact of innodb_flush_log_at_trx_commit

The default value 1 forces the log buffer to be written and flushed to disk at every transaction commit, causing significant disk‑I/O latency. Changing the variable to 0 makes MySQL write the log buffer to the file once per second, eliminating the per‑commit flush.

Setting innodb_flush_log_at_trx_commit = 0 dramatically reduced the latency of the insert statement, but it introduces a risk: a crash within the last second could lose those transactions. For the tested application the risk was acceptable.

Checking system I/O load

High I/O pressure often explains slow query end times. The iostat -d -x -k 1 40 command shows disk utilization; the %util column near 100 % indicates the device is saturated.

Identifying offending processes

Linux’s iotop utility lists processes with the highest I/O usage. After installing via yum install iotop, the screenshot shows a rsync script dominating read I/O and several crawlers plus Elasticsearch consuming write I/O.

Resolution

By throttling the crawler processes, the insert latency improved noticeably, confirming that excessive I/O was the bottleneck.