詭異的druid連接池連接斷開故障經驗總結
- 背景
- 症狀
- 排查
- 修復
背景
最近在陸續作機房升級相關工做，配合DBA對產線數據庫連接方式作個調整，將原來直接連接讀庫的地址切換到統一的讀負載均衡的代理 haproxy 上，方便機櫃和服務器的搬遷。
切換以後線上時不時的會發生 discard connection 錯誤，致使程序報 500 錯誤，但不是每次都必現的。mysql
開發框架: spring boot+mybatis+druid+shardingJDBC
網絡架構:
appserver->mysql(master) 寫
appserver->haproxy->mysql(slave)/n 讀git
第一反應確定是由於此次的讀庫地址的變更引發的問題，以爲問題應該是 druid 連接池中的 connection 保活策略沒起做用，只要作下配置修改應該就能夠了。結果這個問題讓咱們排查了好幾天，咱們居然踩到了千年難遇的深坑。github
這個問題排查的很坎坷，一次次的吐血，最終咱們定位到問題而且優雅的修復了，咱們一塊兒來體驗下這個一次一次讓你絕望一次一次打臉的過程。redis
症狀
先說故障症狀，常常出現以下錯誤：spring
discard connection
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failuresql
The last packet successfully received from the server was 72,557 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago.數據庫
根據錯誤日誌初步判斷確定是與 db 之間的連接已經斷開，嘗試使用了一個已經斷開的連接纔會引發這個錯誤發生。可是根據咱們對 druid 瞭解，druid 有連接檢查功能，按理不會拿到一個無效連接纔對，帶着這個線索咱們上路了。後端
排查
爲了準確的知道 db 的連接的存活時間，瞭解到 haproxy 對轉發的 db tcp 連接空閒時間在 1m 以內，超過 1m 不活動就會被關掉。也就說咱們與 db 之間的原來的長連接在 1m 以內會被斷開。咱們先無論這個時間設置的是否符合全部的大併發場景，至少在 druid 的連接池裏會有有效連接檢查，應該不會拿到無效連接纔對，咱們作了配置調整。服務器
咱們看下 druid 跟連接時間相關的配置：網絡
datasource.druid.validationQuery=SELECT 1 datasource.druid.validationQueryTimeout=2000 datasource.druid.testWhileIdle=true datasource.druid.minEvictableIdleTimeMillis=100000 datasource.druid.timeBetweenEvictionRunsMillis=20000
配置的每項的意思這裏就不解釋了。
咱們啓用了 testWhileIdle 配置，讓每次拿取連接的時候發起檢查。根據 timeBetweenEvictionRunsMillis 的配置只有大於這個時間 druid 纔會發起檢查，因此可能的場景是拿到一個即將過時的連接，根據這個線索咱們調整這個時間爲 20000ms，也就是超過 20s 會檢查當前拿取的連接肯定是否有效，檢查的方式應該是使用 validationQuery 配置的 sql 語句纔對，可是發現咱們並找不到任何有關於 SELECT 1 的痕跡。
爲何你死活找不到 SELECT 1
首先要搞清楚 validationQuery 爲何沒起做用，帶着這個疑問開始 debug druid 源碼。
if (isTestWhileIdle()) {
final long currentTimeMillis = System.currentTimeMillis();
final long lastActiveTimeMillis = poolableConnection.getConnectionHolder().getLastActiveTimeMillis();
final long idleMillis = currentTimeMillis - lastActiveTimeMillis;
long timeBetweenEvictionRunsMillis = this.getTimeBetweenEvictionRunsMillis();
if (timeBetweenEvictionRunsMillis <= 0) {
timeBetweenEvictionRunsMillis = DEFAULT_TIME_BETWEEN_EVICTION_RUNS_MILLIS;
}
if (idleMillis >= timeBetweenEvictionRunsMillis) {
boolean validate = testConnectionInternal(poolableConnection.getConnection());
if (!validate) {
if (LOG.isDebugEnabled()) {
LOG.debug("skip not validate connection.");
}
discardConnection(realConnection);
continue;
}
}
}
}
閒置時間確定會有大於 timeBetweenEvictionRunsMillis 時間的，會發起 testConnectionInternal 方法檢查。咱們繼續跟進去看，
protected boolean testConnectionInternal(DruidConnectionHolder holder, Connection conn) {
boolean valid = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout);
內部會使用 validConnectionChecker 檢查對象發起檢查。
public boolean isValidConnection(Connection conn, String validateQuery, int validationQueryTimeout) throws Exception {
if (conn.isClosed()) {
return false;
}
if (usePingMethod) {
if (conn instanceof DruidPooledConnection) {
conn = ((DruidPooledConnection) conn).getConnection();
}
if (conn instanceof ConnectionProxy) {
conn = ((ConnectionProxy) conn).getRawObject();
}
if (clazz.isAssignableFrom(conn.getClass())) {
if (validationQueryTimeout < 0) {
validationQueryTimeout = DEFAULT_VALIDATION_QUERY_TIMEOUT;
}
try {
ping.invoke(conn, true, validationQueryTimeout * 1000);
} catch (InvocationTargetException e) {
Throwable cause = e.getCause();
if (cause instanceof SQLException) {
throw (SQLException) cause;
}
throw e;
}
return true;
}
}
String query = validateQuery;
if (validateQuery == null || validateQuery.isEmpty()) {
query = DEFAULT_VALIDATION_QUERY;
}
Statement stmt = null;
ResultSet rs = null;
try {
stmt = conn.createStatement();
if (validationQueryTimeout > 0) {
stmt.setQueryTimeout(validationQueryTimeout);
}
rs = stmt.executeQuery(query);
return true;
} finally {
JdbcUtils.close(rs);
JdbcUtils.close(stmt);
}
}
debug 這裏才發現，druid 默認採用的是 mysql.ping 來作連接有效性檢查。
druid 默認採用msyql.ping 協議檢查
那是否是用 msyql.ping 協議並不會讓 mysql 從新滑動 session 閒置時間，帶着這個問題打開 information_schema.processlist 進程列表查看會不會刷新會話時間，經過 debug發現是會刷新時間的，說明沒有問題，這條線索算是斷了。
haproxy tiemout主動close上下游連接
調整方向，開始懷疑是否是 haproxy 的一些策略致使連接失效，開始初步懷疑 haproxy 的輪訓轉發後端連接是否是有相關會話保持方式，是否是咱們配置有誤致使 haproxy 的連接和 mysql 連接篡位了。
固然這個猜測有點誇張，可是沒辦法，技術人員就要有懷疑一切的態度。
爲了還原產線的網絡路線，我在本地搭了一個 haproxy，瞭解下他的工做原理和配置，圖方便我就用了yum順手裝了一個，版本是 HA-Proxy version 1.5.18 不知道是我本地環境問題仍是這個版本的 bug，咱們配置的 mode tcp 活動檢查一直不生效。
listen service 127.0.0.1:60020 mode tcp balance roundrobin option tcplog server server1 192.168.36.66:3306 check inter 2000 rise 2 fall 3 server server2 192.168.36.66:3306 check inter 2000 rise 2 fall 3
因爲 haproxy 活動檢查一直不經過，因此沒法轉發個人連接，搞了半天我只能手動裝了一個低版本的 haproxy HA-Proxy version 1.4.14 。
完整的配置：
defaults
mode tcp
retries 3
option redispatch
option abortonclose
maxconn 32000
timeout connect 2s
timeout client 5m
timeout server 5m
listen test1
bind 0.0.0.0:60000
mode tcp
balance roundrobin
server s1 192.168.36.66:3306 weight 1 maxconn 10000 check inter 10s
server s2 192.168.36.66:3306 weight 1 maxconn 10000 check inter 10s
server s3 192.168.36.66:3306 weight 1 maxconn 10000 check inter 10s
1.4 的版本順利完成活動檢查。
我使用 haproxy 進行debug，調試下來也都沒有問題，也翻了下 haproxy 如何轉發連接的，內部經過會話的方式保持兩個連接的關係，若是是 tcp 長連接應該不會出現什麼問題。haproxy 在 http 模式下有會話保持方式，tcp 應該是直接捆綁的方式，一旦到 timeout 時間會主動 close 和 mysql 的連接，並且沒有出現篡位的問題。到這裏線索又斷了。
自定義 ValidConnectionChecker 埋點日誌
沒有辦法，只能試着埋點 druid 的檢查日誌，排查內部上一次的 check和報錯之間的時間差和 connectionId 是否是一致的。
public class MySqlValidConnectionCheckerDebug extends MySqlValidConnectionChecker {
@Override
public boolean isValidConnection(Connection conn, String validateQuery, int validationQueryTimeout) {
Long connId = 0L;
try {
Field connField = ConnectionImpl.class.getDeclaredField("connectionId");
connField.setAccessible(true);
connId = (Long) connField.get(((ConnectionProxyImpl) conn).getConnectionRaw());
} catch (Exception e) {
log.error("valid connection error", e);
} finally {
log.info("valid connection ok. conn:" + connId);
}
return true;
}
爲了拿到 connectionId 只能反射獲取，在本地debug下沒問題，能正常拿到 connectionId，可是發到驗證環境進行驗證的時候報錯了，以爲奇怪，仔細看了下原來開發環境的配置和驗證和生產的不同，開發環境沒有走讀寫分離。
驗證和生產都是使用了 mysql 的 replication 的機制，因此致使我反射獲取的代碼報錯。
datasource.druid.url=jdbc:mysql:replication
經過debug發現，原來 __druid__的 connection 是 JDBC4Connection ，變成了 ReplicationConnection ，並且裏面包裝了兩個 connection ，一個 masterconnection ，一個 slaveconnection ，彷佛問題有點浮現了。
經過debug發現 druid 的檢查仍是會正常走到，當走到 ReplicationConnection 內部的時候 ReplicationConnection 有一個 currentConnection ，這個連接是會在 masterConnection 和 slaveConnection 之間切換，切換的依據是 readOnly 參數。
在檢查的時候因爲 druid 並不感知上層的參數，readOnly 也就不會設置。因此走的是 masterConnection ，可是在程序裏用的時候經過 spring 的 TransactionManager 將 readOnly 傳播到了 ShardingJDBC ， ShardingJDBC 在設置到 ReplicationConnection 上，最後致使真正在使用的時候其實使用的是 slaveConnection。
找到這個問題以後去 druid github Issues 搜索了下果真有人提過這個問題，在高版本的 druid 中已經修復這個問題了。
修復
修復這個問題有兩個方法，第一個方法，建議升級 druid，裏面已經有 MySqlReplicationValidConnectionChecker 檢查器專門用來解決這個問題。第二個方法就是本身實現 ValidConnectionChecker 檢查器，可是會有在未來出現bug的可能性。
因爲時間關係文章只講了主要的排查路線，事實上咱們陸續花了一週多時間，再加上週末連續趴上十幾個小時才找到這根本問題。
這個問題之因此難定位的緣由主要是牽扯的東西太多，框架層面、網絡連接層面、mysql服務器層面，haproxy代理等等，固然其中也繞了不少彎路。。
下面分享在這個整個排查過程當中的一些技術收穫。
相關技術問題
1.mysqlConenction提供了ping方法用來作活動檢查，默認MySqlValidConnectionChecker使用的是pinginternal。
ping = clazz.getMethod("pingInternal", boolean.class, int.class);
2.低版本的druid不支持自定義 ValidConnectionChecker 來作個性化的檢查。
3.druid 的test方法使用注意事項，testOnBorrow 在獲取連接的時候進行檢查，與testWhileIdle是護持關係。
if (isTestOnBorrow()) {
} else {
if (isTestWhileIdle()) {
3.kill mysql processlist 進程會話到連接端tcp狀態有延遲，這是tcp的四次斷開延遲。
4.haproxy 1.5.18 版本 mode tcp check不執行，健康檢查設置無效。
5.mysql replication connection master/slave切換邏輯須要注意，會不會跟上下油的連接池組合使用出現bug，尤爲是分庫不表、讀寫分離、自定義分片。
6.排查mysql服務器的問題時，打開各類日誌，操做日誌，binlog日誌。
7.springtransactionmanagenent 事務傳播特性會影響下游數據源的選擇，setreadonly、setautocommit。
8.低版本的 druid MySqlValidConnectionChecker 永遠執行不到 ReplicationConnection ping 方法。
做者：王清培(滬江網資深架構師)
- 1. Druid 連接池
- 2. Druid連接及PLSQL 經常自動斷開失去連接
- 3. druid 數據池連接異常
- 4. Druid連接池連接超時，獲取不到連接
- 5. Druid數據庫連接池
- 6. druid和c3p0連接池
- 7. Druid連接池技術
- 8. druid數據庫連接池
- 9. springboot配置druid連接池
- 10. Druid連接池(無框架)
- 更多相關文章...
- • PHP 連接 MySQL - PHP教程
- • SQL 連接(JOIN) - SQL 教程
- • PHP開發工具
- • 算法總結-雙指針
-
每一个你不满意的现在，都有一个你没有努力的曾经。
- 1. Druid 連接池
- 2. Druid連接及PLSQL 經常自動斷開失去連接
- 3. druid 數據池連接異常
- 4. Druid連接池連接超時，獲取不到連接
- 5. Druid數據庫連接池
- 6. druid和c3p0連接池
- 7. Druid連接池技術
- 8. druid數據庫連接池
- 9. springboot配置druid連接池
- 10. Druid連接池(無框架)