MySQL Network Write Timeout (Error 1161) Analysis and Debugging

Problem Description

A customer using TDSQL MySQL 8.0 encountered intermittent connection interruptions while processing batch jobs that stream 2,000 rows at a time with roughly 30‑second gaps between batches. The reported error messages include:

ERROR c.a.d.p.DruidPooledPreparedStatement - getMaxFieldSize error
java.sql.SQLException: No operations allowed after statement closed.
...

The batch workload fetches data in a streaming fashion, processes each batch, then proceeds to the next batch.

Problem Analysis

Reviewing MySQL logs revealed no explicit disconnect entries, but the slow‑query log showed statements with Errno: 1161 (KILLED: 0) during the failure window, for example:

# Query_time: 602.623354 Lock_time: 0.000556 Usecs_wait_tp_wq: 0 Rows_sent: 17176 Rows_examined: 268505 Thread_id: 3180834
Errno: 1161 Killed: 0 Bytes_received: 0 Bytes_sent: 3236280 Read_first: 0 Read_last: 0 Read_key: 33
Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 167 Sort_merge_passes: 0 Sort_range_count: 0
Start: 2023-05-10T10:29:09.170404+08:00 End: 2023-05-10T10:39:11.793758+08:00

Error 1161 corresponds to ER_NET_WRITE_INTERRUPTED , meaning a timeout occurred while writing communication packets. The server’s net_write_timeout was set to 600 seconds, indicating the timeout originated elsewhere.

Investigation of MySQL 8.0 source code shows that error 1161 is generated only when the operating system returns ETIMEDOUT . The write path is:

vio_write → mysql_socket_send → vio_socket_io_wait → vio_io_wait

During the socket send, MySQL may retry after net_retry_times encounters of EAGAIN , eventually calling poll() . If poll() times out, MySQL treats the timeout as ETIMEDOUT and returns error 1161.

When the packet is ready, net_write_raw_loop sends the data; any abnormality results in ER_NET_WRITE_INTERRUPTED or ER_NET_ERROR_ON_WRITE . The final check is performed by vio_was_timeout , which maps the failure to ETIMEDOUT .

Both ER_NET_WRITE_INTERRUPTED (error 1161) and ER_NET_ERROR_ON_WRITE (error 1160) are macro definitions for these error codes.

Increasing net_write_timeout to 10800 seconds alleviated most incidents, but occasional 30‑second Errno: 1161 entries persisted, suggesting additional timeout sources.

# Query_time: 28.221121 Lock_time: 0.000006 Usecs_wait_tp_wq: 0 Rows_sent: 5809 Rows_examined: 268505 Thread_id: 13364592 Errno: 1161 Killed: 0 Bytes_received: 0 Bytes_sent: 1060392 Read_first: 1 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 167 Sort_merge_passes: 0 Sort_range_count: 0 Start: 2023-05-13T15:13:50.683868+08:00 End: 2023-05-13T15:14:18.904989+08:00

TCP dump analysis showed that MySQL was still transmitting data when a FIN packet from the client caused the connection to close. The proxy host exhibited a high TCPRcvQDrop count, indicating active packet drops at the TCP layer.

Debugging Analysis

To pinpoint the trigger, additional logging was added to MySQL source:

In vio_write , log the return value of mysql_socket_send (which ultimately calls send() ).

In vio_io_wait , log the return value of poll() .

Reproducing the client’s read pattern on a local two‑shard TDSQL 8.0 cluster yielded the following observations:

All poll() logs returned 1 , indicating no poll timeout and that net_write_timeout was not the cause.

# grep -i 'poll ret' /data1/tdengine/log/4008/dblogs/mysqld.err | sort | uniq
TXSQL: The vio_io_wait poll ret is 1.

System call send() returned errno values 11, 104, and 110:

# grep -i -E 'The error is' /data1/tdengine/log/4008/dblogs/mysqld.err | sort | uniq
TXSQL: The error is 104.
TXSQL: The error is 11.
TXSQL: The error is 110.

When the server’s send() attempts to deliver data to a crashed client, the missing ACK triggers repeated retransmissions. Linux’s TCP retransmission policy (controlled by /proc/sys/net/ipv4/tcp_retries2 ) aborts after a configurable number of retries (default 6–15). After the final retry, the kernel returns ETIMEDOUT or EHOSTUNREACH . If the server ignores this and calls send() again, it receives a Broken pipe error.

The current OS setting is 6 retries (≈26‑27 seconds). Reducing tcp_mem to “1 2 3” allowed local reproduction with net_write_timeout set to 300 seconds.

Sample slow‑log entry confirming a ~30‑second duration:

# Query_time: 26.631368 Lock_time: 0.000629 Usecs_wait_tp_wq: 0 Rows_sent: 167 Rows_examined: 167 Thread_id: 32
Errno: 1161 Killed: 0 Bytes_received: 0 Bytes_sent: 24576 Read_first: 1 Read_last: 0 Read_key: 1
Start: 2023-05-22T20:54:06.175770+08:00 End: 2023-05-22T20:54:32.807138+08:00

Summary and Recommendations

MySQL generates error 1161 in two situations:

The write buffer becomes full, poll() waits longer than net_write_timeout (function vio_io_wait ).

The send() system call fails with ETIMEDOUT or related errors (function vio_write ).

To mitigate the issue, consider the following actions:

Optimize the application’s data‑reading logic to reduce sustained write pressure.

Increase net_write_timeout appropriately (e.g., to several hours if needed).

Adjust OS‑level TCP parameters, such as net.ipv4.tcp_mem (e.g., set minimum 6 GB, pressure 8 GB, maximum 12 GB) to reduce packet drops.

-END-