引言

上周一去公司,被領(lǐng)導(dǎo)叫過去詢問,業(yè)務(wù)監(jiān)控平臺 "批處理"任務(wù), 是不是更改執(zhí)行時間了磨镶，從原先的每小時整點執(zhí)行變?yōu)楝F(xiàn)在的每小時16&45min 執(zhí)行置森。
第一反應(yīng)很懵,45min執(zhí)行是此前做"測試"(稍后分析這個"測試")時 更改的，但每小時 16min執(zhí)行攻臀，確實沒有改過,難道是其他同事改過?(業(yè)務(wù)監(jiān)控已經(jīng)交接給其他同事了),
但應(yīng)該不可能.雖然領(lǐng)導(dǎo)說是問問,不用改,但還是一連忐忑了幾天. 趁著 T+1 聯(lián)調(diào),事情不太多，回頭重新查看這個問題.

問題背景:

從備份庫切換回生產(chǎn)庫(100節(jié)點),然后問題就來了...

問題描述:

1.每次整點執(zhí)行時,比如早上9:00,線程都會hang住一段時間,然后在9:15:46,前臺調(diào)度頁面顯示執(zhí)行完成,后臺卻在9:15:00 拋出"連接超時"異常。
因為當(dāng)時在做遷移,沒有更多時間來分析,所以將 執(zhí)行時間從整點執(zhí)行 更新 到 每小時45min,后續(xù)的效果來看,并未出現(xiàn)預(yù)料之外的情況.

原因分析:

如下為簡化后的大致流程圖:

image.png

將從幾個方面來分析:
調(diào)度器要门、Druid數(shù)據(jù)源、JDBC超時廓啊、Oracle服務(wù)端等幾個方面來分析欢搜。

其實解決這個問題最簡單，直接有效的方法 ,根據(jù)現(xiàn)有的問題特征(這個問題在備份庫是不存在的)
從生產(chǎn)庫(100節(jié)點) 查詢 :

• oracle 后臺 net 日志
• oracle 服務(wù)端對jdbc 連接超時的配置
• 操作系統(tǒng)底層對socket超時的配置
• 防火墻
  通過如上四個方面,基本可以確定問題產(chǎn)生的原因,不過 因為是生產(chǎn)庫,也許 通常是沒有權(quán)限去這么做的吧,那只能通過其他途徑去查詢原因了.

一:調(diào)度器

調(diào)度器的原因,是可以排除的谴轮，前臺調(diào)度頁面,顯示執(zhí)行開始時間 是在 09:45,而 后臺記錄顯示炒瘟，線程在被hang住15分鐘后,拋出異常，重新獲取連接后,將整個流程執(zhí)行完畢第步！
15分鐘,是不是很巧呢疮装？

二:Druid數(shù)據(jù)源

問題特征:
1.線程在指定的時間啟動,在hang住15分鐘后，拋出"connection time out";
2.監(jiān)控平臺 與 "100節(jié)點"并不在一個網(wǎng)段中,對于內(nèi)網(wǎng),考慮會有防火墻的存在等脂。
3.Druid連接池,對于連接的超時時間設(shè)置在60sec(100節(jié)點對連接的超時控制無法知曉,不過可以反推出來);

問題分析:

2.1 線程 在 被hang住的這段時間里爆价，到底在做什么？
用jstat查看jvm內(nèi)存使用情況,發(fā)現(xiàn)各區(qū)內(nèi)存占用率較低，查看GC信息也沒有異常腾它。
再接茬查看線程棧，發(fā)現(xiàn)線程 hang 在socket底層的TCP套接字讀取上:如圖:

微信圖片_20190714220852.jpg

• 當(dāng)請求與服務(wù)器建立連接時，線程執(zhí)行Socket的帶參數(shù)的構(gòu)造方法，或執(zhí)行Socket的connect()方法時滚局，會進(jìn)入阻塞狀態(tài)，直到連接成功顽频，此線程才從Socket的構(gòu)造方法或connect()方法返回藤肢。

• 當(dāng)監(jiān)控平臺向服務(wù)器提交數(shù)據(jù)(query命令),線程從Socket的輸入流讀取服務(wù)器的響應(yīng)數(shù)據(jù);如果沒有足夠的數(shù)據(jù)，就會一直處于阻塞狀態(tài)糯景，以等待數(shù)據(jù)的到來,處于hang住的狀態(tài),Thread.interrupt()也無法結(jié)束掉這個線程.

• 直到讀到了足夠的數(shù)據(jù)嘁圈，或者到達(dá)輸入流的末尾，或者出現(xiàn)了異常蟀淮，才從輸入流的read()方法返回或異常中斷最住。

通過跟蹤 druid 代碼,當(dāng)前線程正在執(zhí)行 query-"select 1 from dual",這是一條驗證sql,本身不會有太大的數(shù)據(jù)量，但 線程一直 hang 住,等待服務(wù)端的響應(yīng)(等待服務(wù)端寫入數(shù)據(jù),服務(wù)端寫入數(shù)據(jù)完成會發(fā)送結(jié)束標(biāo)志), 最可能的一種情況,服務(wù)端將該連接關(guān)閉,導(dǎo)致客戶端無響應(yīng)怠惶，一直處于等待狀態(tài)涨缚。

一段時間后(15min),拋出"connection time out" (在沒找到準(zhǔn)確原因之前,將執(zhí)行時間提前15min,也就是每個小時45min執(zhí)行);

二:原因分析：

業(yè)務(wù)線程一直處于runable狀態(tài),但是一直hang住卻沒有返回值, 而方法鏈調(diào)用的源頭是 Druid連接池的isValidConnection()方法。 問題似乎與 Druid的配置有關(guān).
Druid在獲取連接后,在驗證連接的有效性時,被hang住,難道是連接超時了 ?

根據(jù)線程 是在調(diào)用 socketread 與服務(wù)端通信時 hang 住,且 調(diào)用源頭來自 druid的 isValidConnection發(fā)起策治。
可以推斷脓魏，是否連接因為超時,被服務(wù)端關(guān)閉，導(dǎo)致客戶端發(fā)起socketread無響應(yīng),長時間 hang住 呢 ?
當(dāng)前 druid 中配置的連接有效時長為60 sec ;

2.2 DruidAbstractDataSource源碼分析:

public boolean isValidConnection(Connection conn, String query, int validationQueryTimeout) throws Exception {
        if (query == null || query.length() == 0) {
            return true;
        }
        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);
        }
    }

查看調(diào)用鏈通惫，在執(zhí)行如上代碼時 hang 住 , isValidConnection 的調(diào)用參數(shù)中茂翔，包含一個validationQueryTimeout,是否因為沒有設(shè)置validationQueryTimeout或者設(shè)置的時間過長導(dǎo)致的呢？
1》在訪問核心100節(jié)點的數(shù)據(jù)源中讽膏，配置validationQueryTimeout時長為:15s ,即 客戶端等待服務(wù)端響應(yīng),超過15sec 服務(wù)端無響應(yīng)后拋出異常檩电，中斷 被 hang 住的狀態(tài)。
然而并沒有效果~(自己都笑了);

Druid連接池里的連接(100節(jié)點)是超時的,那為什么沒有被kill掉府树，配置的有效時長60sec.

Druid執(zhí)行空閑連接的校驗源碼：

public class DestroyTask implements Runnable {

    @Override
    public void run() {
        shrink(true, keepAlive);

        //空閑連接的處理
        if (isRemoveAbandoned()) {
            removeAbandoned();
        }
    }
}

此處代碼太長俐末，是druid高效的核心，截取一段：

final int checkCount = poolingCount - minIdle;
    final long currentTimeMillis = System.currentTimeMillis();
    for (int i = 0; i < poolingCount; ++i) {
        DruidConnectionHolder connection = connections[i];

        if (checkTime) {
            if (phyTimeoutMillis > 0) {
                long phyConnectTimeMillis = currentTimeMillis - connection.connectTimeMillis;
                if (phyConnectTimeMillis > phyTimeoutMillis) {
                    evictConnections[evictCount++] = connection;
                    continue;
                }
            }

            long idleMillis = currentTimeMillis - connection.lastActiveTimeMillis;

            if (idleMillis < minEvictableIdleTimeMillis) {
                break;
            }

            if (checkTime && i < checkCount) {
                evictConnections[evictCount++] = connection;
            } else if (idleMillis > maxEvictableIdleTimeMillis) {
                evictConnections[evictCount++] = connection;
            } else if (keepAlive) {
                keepAliveConnections[keepAliveCount++] = connection;
            }
        } else {
            if (i < checkCount) {
                evictConnections[evictCount++] = connection;
            } else {
                break;
            }
        }
    }

    int removeCount = evictCount + keepAliveCount;
    if (removeCount > 0) {
        System.arraycopy(connections, removeCount, connections, 0, poolingCount - removeCount);
        Arrays.fill(connections, poolingCount - removeCount, poolingCount, null);
        poolingCount -= removeCount;
    }
    keepAliveCheckCount += keepAliveCount;
} finally {
    lock.unlock();
}

此處需注意的是：

• 與其他連接池邏輯不同奄侠，druid將超時的連接卓箫，所有連接，全部拋棄,并不依賴最小連接數(shù)的限制,將復(fù)雜問題簡化垄潮。
• Druid判斷連接是否超時的依據(jù)烹卒，來源 min 和 max. min當(dāng)前監(jiān)控平臺設(shè)置的是60s,max為drudi默認(rèn)的值,為7個小時，為什么默認(rèn)是7個小時弯洗，為什么不是6個小時或者8個小時旅急，這里不是巧合，后續(xù)再討論這個"7個小時".

至少到這里牡整，連接超時的原因找到了藐吮，引出了另一個問題: 為什么配置 statement的validationQueryTimeout超時，沒有達(dá)到 超時中斷線程的作用 ？

三:JDBC 超時

SUN公司一共定義了4中類型的JDBC谣辞，常用的是第四種迫摔，該類型的Driver完全由Java代碼實現(xiàn)，通過使用socket與數(shù)據(jù)庫進(jìn)行通信

image.png

通過socket對字節(jié)流進(jìn)行處理泥从，當(dāng)在網(wǎng)絡(luò)操作中遇到問題的時候句占，將會消耗大量的cpu資源，并且失去響應(yīng)超時躯嫉。

應(yīng)用與數(shù)據(jù)庫間的timeout層級

image.png

即：簡化后纱烘，應(yīng)用 與 數(shù)據(jù)庫的 timeout層級。
高級別的 timeout 依賴于低級別的 timeout ,只有當(dāng)?shù)图墑e的 timeout無誤時,高級別的 timeout才能確保在正常祈餐。
例如：當(dāng) socket timeout 出現(xiàn)問題時, 高級別的 statement timeout 和 transcation timeout都將失效凹炸。

• 即使 設(shè)置了 statement timeout 時，當(dāng)網(wǎng)絡(luò)出錯時,應(yīng)用 也 無法從錯誤中恢復(fù)昼弟。
• statement timeout 無法處理網(wǎng)絡(luò)連接失敗的超時啤它，它能做的僅僅是限制 statement 的操作時間。
• 網(wǎng)絡(luò)連接失敗時的 timeout 必須交由JDBC Socket 來處理,Socket控制著節(jié)點之間網(wǎng)絡(luò)通信舱痘。

Druid是數(shù)據(jù)庫連接的創(chuàng)建和管理变骡，并不干涉timeout的處理。
當(dāng)連接在Druid中創(chuàng)建芭逝，或是Druid發(fā)送校驗query檢查連接有效性的時候塌碌，socket timeout將會影響這些過程，但并不直接對應(yīng)用造成影響旬盯。

當(dāng)在應(yīng)用中調(diào)用Druid的getConnection()方法時台妆，可以設(shè)置獲取數(shù)據(jù)庫連接的超時時間，但是這和JDBC的timeout毫不相關(guān)胖翰。

3.1 JDBC的statement timeout處理過程

設(shè)置的是一個statement的執(zhí)行超時時間接剩，即driver等待statement執(zhí)行完成，接收到數(shù)據(jù)的超時時間
注意:
statement的timeout不是整個查詢的timeout萨咳，只是statement執(zhí)行完成并拉取fetchSize數(shù)據(jù)返回的超時;
resultSet的next在必要的時候還會觸發(fā)fetch數(shù)據(jù)懊缺，每次fetch的超時時間是單獨(dú)算的，默認(rèn)也是以statement設(shè)置的timeout為準(zhǔn)

3.1.1 Oracle JDBC Statement的QueryTimeout處理過程

1. 通過調(diào)用Connection的createStatement()方法創(chuàng)建statement
2. 調(diào)用Statement的executeQuery()方法
3. statement通過自身connection將query發(fā)送給Oracle數(shù)據(jù)庫
4. statement在OracleTimeoutPollingThread（每個classloader一個）上進(jìn)行注冊
5. 達(dá)到超時時間
6. OracleTimeoutPollingThread調(diào)用OracleStatement的cancel()方法
7. 通過connection向正在執(zhí)行的query發(fā)送cancel消息

3.2 JDBC的 socket Timeout ?

1.JDBC使用socket與數(shù)據(jù)庫連接培他，數(shù)據(jù)庫并不對應(yīng)用與數(shù)據(jù)庫間的連接超時進(jìn)行處理鹃两。
2.JDBC的 socket timeout 在數(shù)據(jù)庫被突然停掉或是發(fā)生網(wǎng)絡(luò)錯誤（由于設(shè)備故障等原因）時十分重要。
3.由于TCP/IP的結(jié)構(gòu)原因舀凛，socket沒有辦法探測到網(wǎng)絡(luò)錯誤俊扳，因此應(yīng)用也無法主動發(fā)現(xiàn)數(shù)據(jù)庫連接斷開。
4.如果沒有設(shè)置socket timeout的話猛遍，應(yīng)用在數(shù)據(jù)庫返回結(jié)果前會無期限地等下去馋记，這種連接被稱為dead connection碎绎。

設(shè)置的是jdbc I/O socket read and write operations的超時時間，防止因網(wǎng)絡(luò)問題或數(shù)據(jù)庫問題抗果，導(dǎo)致driver一直阻塞等待。(建議比statement timeout的時間長)

為了避免 dead connections奸晴，socket 必須要有超時配置冤馏。
socket timeout可以通過JDBC設(shè)置，socket timeout 能夠避免應(yīng)用在發(fā)生網(wǎng)絡(luò)錯誤時產(chǎn)生無休止等待的情況寄啼，縮短服務(wù)失效的時間逮光。

使用原則:

• socket timeout 的超時時長 必須 大于 statement timeout；
• 不推薦使用socket timeout來限制statement的執(zhí)行時長墩划，因此socket timeout的值必須要高于 statement timeout涕刚，否則，socket timeout將會先生效乙帮，這樣statement timeout就變得毫無意義杜漠，也無法生效。

四:結(jié)論

目前察净，分析了 監(jiān)控平臺連接池中的連接(100節(jié)點)為什么超時 以及 為什么設(shè)置 statement超時沒有任何效果驾茴。
4.1 為什么會在每小時45min執(zhí)行：
因為連接超時，服務(wù)端關(guān)閉連接氢卡，導(dǎo)致客戶端socketRead讀取時锈至，服務(wù)端無響應(yīng)，長時間 hang 住译秦。時長15min.所以峡捡，當(dāng)時在沒有查清原因之前,為了 在 準(zhǔn)點執(zhí)行,在當(dāng)時測試此問題時,將執(zhí)行時間提前15min.

4.2 為什么會在每小時16min執(zhí)行？

• 造成這個異常時間點執(zhí)行"批處理"監(jiān)控任務(wù)筑悴，雖然看似詭異们拙，還是可以還原執(zhí)行原理：在執(zhí)行"批處理"時，若 連接池中包含N個連接阁吝，則延遲的時間在N*15;
• 假設(shè)09:45開始執(zhí)行"批處理"監(jiān)控任務(wù)睛竣，此時,因為平臺在09:00時執(zhí)行過其他任務(wù)(訪問100節(jié)點),連接池中剩余2個idle connection,其 idle time = 45min,訪問100節(jié)點時,將會因連接超時，導(dǎo)致服務(wù)端Close.才產(chǎn)生文章開頭的"hang住15min"后拋出timeout 異常求摇。
• 由此可推斷射沟，100節(jié)點對連接的超時時間，不超過45min.
• 2個 idle 連接將耗費(fèi)30min,實際開始執(zhí)行的時間是在10:15:??(9:45+30min) 開始与境，重新創(chuàng)建連接验夯，查詢數(shù)據(jù)，返回摔刁，并在10:16:?? 返回異常告警提示挥转。

4.3 為什么 每次 hang 住的時間都是15min?

• 因為沒有具體的數(shù)據(jù)，不確定15min是因為防火墻對TCP/IP的超時時間 或者是 OS Socket time out 導(dǎo)致。
• 很多時候, OS time out對socket的配置起決定性作用绑谣。
• OS time out 默認(rèn)為15min(區(qū)分版本),是不是這么巧呢党窜，不要逗我啦~(內(nèi)部防火墻對TCP/IP的阻斷)

4.5 如何解決？

• 根據(jù)目前監(jiān)控平臺的異常特征借宵，以及查閱Druid源碼分析幌衣，可以初步推斷："100節(jié)點"的連接的有效時間，大概是30min左右壤玫。
• 假設(shè)"100節(jié)點"對超時控制在30min豁护，并不意味著query命令可以達(dá)到30min,這取決于socket timeout 和 statement timeout 以及 內(nèi)部防火墻的超時配置,復(fù)雜一點的可能還涉及到OS層。因為沒有確切的數(shù)據(jù)欲间，就不展開分析了楚里。

45&16min問題的解決方案：
在Druid數(shù)據(jù)源中，指定max的具體時長即可猎贴，這需要根據(jù)"100節(jié)點"的數(shù)據(jù)來配置.

以上所有問題的產(chǎn)生班缎，只發(fā)生在"100節(jié)點".

結(jié)尾：
其實,分析到這里，什么結(jié)論也沒有 她渴，是不是 沒有意義呢 ?

• 記錄這段過程吝梅，不在于 有具體的結(jié)論，更多于一種解決問題的思路,對于生產(chǎn)問題的分析,很多時候,解決思路 更重要惹骂，尤其是在極端復(fù)雜的業(yè)務(wù)場景中苏携。
• 其實在再保的幾年中,感受最大的是 解決問題的思路,比 實際解決問題 更重要,當(dāng)不確定問題來源于具體哪一個流程，可以先確定哪一個流程一定是沒有問題的.
• 在此前遇到的各種生產(chǎn)問題, 業(yè)務(wù)場景極其復(fù)雜,模塊結(jié)構(gòu)交織,數(shù)據(jù)量龐大,絕大部分問題都要涉及到多個接口交互,多個流程(系統(tǒng)趨于中心化),多套數(shù)據(jù)表 等.
• 比如"金額相差1分錢"对粪，無法確定是結(jié)算,帳單,復(fù)核,還是分保哪個流程的問題右冻，更有可能是復(fù)核，帳單著拭，結(jié)算不在一天纱扭，兌換率的差異導(dǎo)致相差一分錢等。

只是對解決問題的思路 以及 工作中的一段總結(jié)~