由於基本資料型別使用姿勢不對導致的線上"死迴圈"問題排查

weixin_34208283發表於2018-12-02
資料型別

本文要講的是本週我線上上排查的一個"死迴圈"問題，由於前人的疏忽，導致線上在某一時間段內瘋狂呼叫第三方服務，並沒有在預期時間內結束。

線上程式碼為採用多執行緒校驗批量任務，如下所示為模擬場景，很容易可以看出，該段程式碼的邏輯如下：

  1. 首先採用一個大小為100的執行緒安全佇列來模擬待校驗任務
  2. 然後起10個執行緒，每個執行緒都有10s時間不斷的取佇列中的任務進行校驗
  3. 每次校驗都先從佇列中取一個任務出來，校驗不成功就把任務放回待校驗佇列，且每次校驗完後會休息0.1s
  4. 編號為44的校驗任務是一個永遠都過不去的坎
     public void multiThreadCheckTest(){
        //初始化待校驗佇列,大小為100
        ConcurrentLinkedQueue<Integer> queue = new ConcurrentLinkedQueue<>();
        for (int i = 0; i < 100; i++) {
            queue.add(i);
        }

        int threads = 10; //起10個執行緒來做校驗任務
        float maxCheckMillis = 10 * 1000;// 單個執行緒最長校驗時間為10s
        try{
            final CountDownLatch latch = new CountDownLatch(threads);
            float startCheckTime = System.currentTimeMillis();
            for (int i = 0; i < threads; i++) {
                new Thread(() -> {
                    try {
                        // 每個執行緒迴圈執行校驗
                        while (!queue.isEmpty() && System.currentTimeMillis() - startCheckTime < maxCheckMillis) {
                            Integer ii = queue.poll();

                            // 模擬線上出現的問題，卡在44這裡執行不過去
                            boolean checkResult = (ii == 44 ? false : true);

                            if(!checkResult){
                                queue.add(ii); //校驗不成功則把任務重新加入到佇列中
                            }
                            Thread.sleep(100);//休息0.1s
                        }
                    } catch (Exception e) {
                        //異常處理
                    } finally {
                        latch.countDown();
                    }
                }).start();
            }
            latch.await();
            while (!queue.isEmpty()) {
                Integer iii = queue.poll();
                System.out.println("No." + iii+ " task check failed within " + (System.currentTimeMillis() - startCheckTime) / 1000 + "s");
            }
        }catch (Exception e){
            //異常處理
        }
    }

依上可知，每個執行緒每秒的檢驗能力為10次，所在在10秒時間10個執行緒的校驗能力為: 10*10 *10 = 1000, 足以處理100個任務，所以這段程式碼的理想情況應該在10s左右的時間結束，可是實際執行情況如下:

5990755-562a1d680dff4ea8.jpg
image-20181201192159038

竟然用了131s，比預期的10倍還多。

而我遇到線上的實際每個執行緒有4分鐘時間來校驗任務，且每次校驗完後沒有休息直接下一次校驗!!!把這個4分鐘如果放大10倍，如果有個任務一直校驗不成功的話，相當於40分鐘時間10個執行緒在不間斷的執行校驗任務(相當於死迴圈)，且這個校驗是呼叫第三方的介面，不僅會把自己給累死，還給了別人很大的壓力。還好我們接收到了機器報警，及時重啟了應用。

為什麼會出現這種情況???

第一眼看到用了多執行緒，佇列，還有CountDownLatch類，我還以為是哪裡用得不當導致程式碼中產生了死鎖，但不管是看程式碼還是分析執行緒堆疊，都發現不了問題。

只有另闢溪徑了，除了上面的執行緒併發問題，接下來只可能是while迴圈的判斷有問題了。這段程式碼有兩個while迴圈，很明顯每二個while沒問題，所以只有第一個while的問題了:

while (!queue.isEmpty() && System.currentTimeMillis() - startCheckTime < maxCheckMillis)

這個while迴圈當佇列為空或到執行了指定的時間後就會停止，佇列明顯不會為空，所以只能靠第二個條件了。

既然和執行緒併發無關，和佇列無關，為了便於分析，對程式碼進行簡化如下:

public void multiThreadCheckTest(){
        try {
            float maxCheckMillis = 10 * 1000;
            float startCheckTime = System.currentTimeMillis();
            while (System.currentTimeMillis() - startCheckTime < maxCheckMillis) {
                Thread.sleep(100);//每校驗一次休息0.1s
            }
            System.out.println((System.currentTimeMillis() - startCheckTime) / 1000);
        } catch (Exception e) {
            //異常處理
        }
    }

理想情況是輸出一個接近10左右的值，可實際上輸出的是131.072.

果不其然，出問題的就在這幾行程式碼裡了。對while迴圈裡的左邊的值進行列印:

public void multiThreadCheckTest(){
        try {
            float maxCheckMillis = 10 * 1000;
            float startCheckTime = System.currentTimeMillis();
            while (System.currentTimeMillis() - startCheckTime < maxCheckMillis) {
                System.out.println(System.currentTimeMillis() - startCheckTime);
                Thread.sleep(100);//每校驗一次休息0.1s
            }
            System.out.println((System.currentTimeMillis() - startCheckTime) / 1000);
        } catch (Exception e) {
            //異常處理
        }
    }

輸出卻和預想中並不一樣:

0.0
0.0
0.0
...
0.0
0.0
0.0
131.072

全部為0.0直到最後用了100多秒時間結束，所以問題只能出現在startCheckTime變數的初始化上了，System.currentTimeMillis()返回的是一個long型別的值，但這裡卻利用java基本資料型別的自動轉換用一個float型別的值來接收，我們將float改為long後輸出如下:

0
102
204
306
409
...
9790
9890
9991
10

最後就是在10秒結束，問題解決。

接著又試了一下將float改為double，輸出如下:

0.0
102.0
208.0
311.0
...
9774.0
9879.0
9980.0
10.081

結果也符合預期!!!

看到這裡你或許和我開始一樣產生了如下的疑問:

  1. long型別佔用8個位元組，double只佔用4個位元組，為什麼long型別能轉換為double?

  2. 為什麼將startCheckTime變數型別改為long和double都可以，偏偏用float就不行呢?

接下來就帶著這兩個疑問來複習下基礎知識了。

首先看看java中基本資料型別分類和佔用的位元組數:


5990755-7affcd5e6fe4ca60.png
image.png

支援的自動型別轉換規則如下:

5990755-d1586681b543e854.jpg
image-20181201204142952
  • 首先解決第一個疑問。

對於byte, short, int和long四個整數類而言，它們在記憶體中都是直接換算成二進位制儲存的， 下面以byte為例:

佔用1位元組即8bit，每一位都是二進位制的0或1，且第一位為表示正負的符號位，最大為0111 1111，轉換為10進製為127，最小為1111 1111，轉換為十進位制為-128(1000 000, 用補碼計算, 負數的袚即原碼非符號位取反加1, -128 = (-1) + (-127) = [1000 0001]原 + [1111 1111]原 = [1111 1111]補 + [1000 0001]補 = [1000 0000]補 ), 所以byte的取值範圍為-128~127。同理

short(-32768~32767),

int(-2147483648~2147483647)

long(-9223372036854774808~9223372036854774807)

而浮點數是以科學計數法的形式儲存，以單精度型別float為例，佔用4個位元組即32bit，第一個bit為符號位，接下來8bits為指數位(取值班範圍為-128-127)，剩下23bits為小數位。所以float的取值範圍為3.402823e+38 ~ 1.401298e-45（e+38表示是乘以10的38次方，e-45表示乘以10的負45次方），同理double雙精度有11個指數位52個小數位，取值範圍為1.797693e+308~ 4.9000000e-324。

由於可知，因為在記憶體中的儲存形式不同，雖然float型別只佔4個位元組，但是表示的數值範圍遠遠大於long的數值範圍， 所以long型別能轉換為float型別。

  • 接下來解決第二個問題。

浮點數之所以稱為浮點，是因為它會產生精度丟失。計算機世界只能用二進位制的小數來表達小數，而我們現實世界是用十進位制的小數來表達。對於二進位制小數，小數點右邊能表達的值是 1/2, 1/4, 1/8, 1/16, 1/32, 1/64, 1/128 … 1/(2^n）。所有這些小數都是一點一點的拼湊出來的一個近似的數值, 所有才會不準確的。

舉個例子, 現在用二進位制來表示十進位制的1.2:
1.01 = 1 + 1/4 = 0.25 , 偏大
1.001 = 1 + 1/8 = 0.125 , 偏小
1.0011 = 1 + 1/8 + 1/16 = 0.1875 ,
1.001101 = 1 + 1/8+ 1/16 + 1/64 = 0.203125 , 又偏大
1.0011001 = 1 + 1/8 + 1/16 + 1/128 = 0.1953125 ,
1.00110011 = 1 + 1/8+1/16+1/128+1/256 = 0.19921875 , 這個很接近
越來越接近…
這就是所謂的用二進位制小數沒法精確表達10進位制小數的意思。

因為浮點數表示的小數位不同所以精度不同。

float：2^23 = 8388608，一共七位，這意味著最多能有7位有效數字，但絕對能保證的為6位，也即float的精度為6~7位有效數字；

double：2^52 = 4503599627370496，一共16位，同理，double的精度為15~16位。

回到我們要解決的問題，列印出System.currentTimeMillis()的一個值:

1543671830108 = 1.543671830108E+12

轉換為float: 10 ^ 12 / 2^ 23 = 119209 ms = 119s (java中為131072ms = 131s, 有待考究)

轉換為double: 10 ^ 12 / 2^ 52 = 0 可以忽略

通過上面計算把時時間戳轉換為float後會損失精度，有一百多秒的精度損失, 轉換為double後幾乎沒有精度損失，這就是為什麼可以將時間戳轉換為double而不能轉換為float了， 當然最好還是直接使用long， 因為long已經足以表達時間戳。

調整後的程式碼如下, 不管怎樣都不會再出現執行時間與預期時間不符的"死迴圈"了:

  1. 將maxCheckMillis， startCheckTime變數型別都改為long
  2. while迴圈裡只有在校驗不成功才暫停0.1s
public void multiThreadCheckTest(){
        //初始化待校驗佇列,大小為100
        ConcurrentLinkedQueue<Integer> queue = new ConcurrentLinkedQueue<>();
        for (int i = 0; i < 100; i++) {
            queue.add(i);
        }

        int threads = 10; //起10個執行緒來做校驗任務
        long maxCheckMillis = 10 * 1000;// 單個執行緒最長校驗時間為10s
        try{
            final CountDownLatch latch = new CountDownLatch(threads);
            long startCheckTime = System.currentTimeMillis();
            for (int i = 0; i < threads; i++) {
                new Thread(() -> {
                    try {
                        // 每個執行緒迴圈執行校驗
                        while (!queue.isEmpty() && System.currentTimeMillis() - startCheckTime < maxCheckMillis) {
                            Integer ii = queue.poll();

                            // 模擬線上出現的問題，卡在44這裡執行不過去
                            boolean checkResult = (ii == 44 ? false : true);

                            if(!checkResult){
                                //校驗不成功則記錄日誌，並休息0.1s, 然後把任務重新加入到佇列中
                                System.out.println(Thread.currentThread() + " check " + ii + " failed!");
                                Thread.sleep(100);//校驗不成功則休息0.1s
                                queue.add(ii);
                            }
                        }
                    } catch (Exception e) {
                        //異常處理
                    } finally {
                        latch.countDown();
                    }
                }).start();
            }
            latch.await();
            while (!queue.isEmpty()) {
                Integer iii = queue.poll();
                System.out.println("No." + iii+ " task check failed within " + (System.currentTimeMillis() - startCheckTime) / 1000 + "s");
            }
        }catch (Exception e){
            //異常處理
        }
    }

總結: 由於疏忽大意使用基本資料型別姿勢不對，while迴圈內的條件判斷沒有在預期時間內為非，最多多出100多s， 也就是兩分鐘的時間一直在重複執行，讓人誤以為出現的死迴圈。所以平時寫程式碼時還是要嚴於律己，不要給以後或後來人留坑。

相關文章