Investigation of DBLE "no handler" Log Entries and MySQL Connection‑Timeout Error Handling

Background

In a production environment, DBLE frequently prints "no handler" logs. Although the logs do not affect business functionality, the root cause and the circumstances that trigger these logs need to be investigated.

Analysis

The first step is to examine both DBLE and MySQL logs to see whether they contain useful clues.

DBLE Log

The DBLE log shows "no handler" entries together with "stream closed by peer" messages, but no other anomalies.

2022-09-02 03:25:23.450  INFO [0-backendWorker] (com.actiontech.dble.net.response.DefaultResponseHandler.closeNoHandler(DefaultResponseHandler.java:116)) - no handler bind in this service MySQLResponseService[isExecuting = false attachment = null autocommitSynced = true isolationSynced = true xaStatus = 0 isDDL = false complexQuery = false] with response handler [null] with rrs = [null]  with connection BackendConnection[id = 342 host = 10.186.62.41 port = 3312 localPort = 51886 mysqlId = 677 db config = dbInstance[name=M1,disabled=false,maxCon=1000,minCon=10]
2022-09-02 03:25:23.450  INFO [0-backendWorker] (com.actiontech.dble.net.connection.BackendConnection.close(BackendConnection.java:125)) - connection id 342 mysqlId 677 close for reason no handler
2022-09-02 03:25:23.450  INFO [1-NIOBackendRW] (com.actiontech.dble.net.service.AbstractService.beforeInsertServiceTask(AbstractService.java:170)) - prepare close for conn.conn id 342,reason [stream closed by peer]
2022-09-02 03:25:23.450  INFO [0-backendWorker] (com.actiontech.dble.net.connection.AbstractConnection.closeImmediatelyInner(AbstractConnection.java:169)) - connection id close for reason [no handler] with connection BackendConnection[id = 342 host = 10.186.62.41 port = 3312 localPort = 51886 mysqlId = 677 db config = dbInstance[name=M1,disabled=false,maxCon=1000,minCon=10]

MySQL Log

The MySQL log records a connection timeout and the subsequent closure of the connection.

2022-09-02T03:25:23.375174Z 672 [Note] [MY-013730] [Server] 'wait_timeout' period of 20 seconds was exceeded for `root`@`%`. The idle time since last command was too long.
2022-09-02T03:25:23.375252Z 677 [Note] [MY-010914] [Server] Aborted connection 677 to db: 'unconnected' user: 'root' host: '10.186.62.148' (The client was disconnected by the server because of inactivity.).

DBLE Logic

Statement Dispatch

DBLE receives a statement from the client.

DBLE selects a connection from its pool to execute the statement.

Based on the statement type, DBLE chooses an appropriate responseHandler (the handler is null for idle connections).

The statement is sent to MySQL.

MySQL Packet Handling

DBLE receives packets sent by MySQL.

If the connection has a non‑null responseHandler , the handler processes the packet.

If no responseHandler is found, DBLE cannot process the packet and prints a "no handler" log.

Backend Connection Close Processing

DBLE receives a FIN packet or detects an abnormal connection.

It logs the close reason and connection details.

It clears the connection’s bound resources (e.g., responseHandler , service objects).

The connection is marked unavailable and removed from the pool.

Normally only connections that have executed statements are closed. If DBLE still uses a closed backend connection to process MySQL data, the "no handler" log appears, which contradicts the expected logic and prompted further investigation.

Arthas Analysis

Arthas commands used: stack com.actiontech.dble.net.response.DefaultResponseHandler closeNoHandler -n 1000 >> closeNoHandler_stack.log watch com.actiontech.dble.net.response.DefaultResponseHandler closeNoHandler '{params,returnObj,throwExp,target}' -n 1000 -x 3 -b >> closeNoHandler.log

The stack trace shows that DBLE receives an error packet from MySQL, calls the error method, and then invokes closeNoHandler , which prints the "no handler" log.

Further inspection revealed that the error packet originates from an idle connection.

Experiment

Set MySQL interactive_timeout to 20 seconds.

Capture traffic on port 3312 with tcpdump -w time_wait.cap .

Start DBLE, wait for the pool connection to timeout, then stop the capture.

Identify the backend connection ID and local port from the DBLE "no handler" log (e.g., mysqlId = 667, localPort = 51886).

Search MySQL error logs for that ID to confirm a timeout‑induced closure.

Filter the capture file by the local port to view the exact packet exchange.

Wireshark analysis shows MySQL first sends an error packet, then a FIN packet, matching the hypothesis.

Error 4031 Details

MySQL 8.0.24 introduced error 4031, which is sent to the client before the connection is closed due to wait_timeout . The release notes confirm that MySQL now sends a detailed error packet prior to closing an idle connection.

Source Code Explanation

Before PR (red/gray parts) : DBLE directly forwards last_errno as a PSH packet, sets net->last_errno to ER_NET_WAIT_ERROR , logs the error, and then closes the connection after writing.

After PR (green/gray parts) : net->last_errno is set to ER_CLIENT_INTERACTION_TIMEOUT , the same logging occurs, and the client receives the error packet (Error 4031) before the connection is closed.

Conclusion

Starting with MySQL 8.0.24, a connection timeout causes MySQL to first send an error packet (Error 4031) and then close the connection. When the timed‑out connection is idle in DBLE’s pool, DBLE receives the error packet, finds no responseHandler , and logs "no handler" – a normal behavior that will be refined in future DBLE versions.

References

https://arthas.aliyun.com/doc/

https://dev.mysql.com/doc/relnotes/mysql/8.0/en/news-8-0-24.html

https://dev.mysql.com/doc/mysql-errors/8.0/en/server-error-reference.html

https://github.com/mysql/mysql-server/commit/14508bbb1790697c28659dd051fbc855cd3b5da9