前言

電視劇《恰同學少年》中，給我印象最深的就是楊昌濟先生晨讀之前大聲朗讀的兩句話：

“楊昌濟，時光易逝，汝當惜之；先賢至理，汝當常憶。”

人生苦短，汝當惜之。向聖賢學習，時常警惕、自審，整理今日所獲如下。

背景

流量分析過程中，有一個定時統計任務，對網路請求資料中的源IP、目的IP、訪問總量進行統計，得到每個源IP，在一天中的各個小時訪問的目的IP、及訪問這些目的IP的總量。統計結果作為為一條記錄，存入Sequoiadb資料庫中。統計結果的實體定義如下：

 public class SourceIpVisitSum {
    private String _id;

    //統計時間
 

    private String date;

    //統計型別
    private String type;

    //源IP訪問資料topN
    private List<SourceVisitInfo> topN;
}

public class SourceVisitInfo implements Comparable<SourceVisitInfo>{
    /**
     * 源IP
     */
    private String srcIp;

    /**
     * 訪問總流量數
     */
    private Long trafficTotal;

    /**
     * 該源IP訪問的目的IP集合:不儲存xml，實時生成xml
     */
 

    private List<String> destIps;

    /**
     * 該源IP訪問過的目的IP的統計結果
     */
    private List<BSONObject> visitServers;

    /**
     * 該該源IP戶當天的訪問趨勢
     */
    private List<TrafficTrendData> trendData;

    /**
     * 日彙總的資料：每天的這個屬性，彙集就是周、月的資料了
     */
    private TrafficTrendData dailyTotal;

｝

public class
 
 TrafficTrendData {
    //統計時間：小時或者天
    private String time;

    //該時間段內的流量總數
    private Long trafficTotal;
｝

抽象這三個實體，統計一天的流量資料中各個源IP的訪問趨勢情況，以JSON格式儲存入庫。業務需求實時展示訪問情況，所以開啟了一個每隔5分鐘統計一次的Quartz定時任務，頁面定時獲取最新的統計結果進行展示。

大流量場景下統計異常

開發過程中進行過測試，隨機插入700萬條的記錄，源IP，目的IP總量不過40個，做一次實時統計操作耗時一分鐘，沒有出現過定時任務積壓的情況。

但是，在真實流量資料場景下，500萬條資料統計過程，耗時40分鐘。統計結果顯示有一萬多個源IP，一千多個目的IP，訪問關係排列總數較多，統計得到的SourceIpVisitSum物件的JSON資料大小達到了34M。而Sequoiadb單條插入的BSON大小限制為16M。

最直接的結果就是，這個每5分鐘一次的統計任務，真正耗時一個多小時，而且統計得到結果準備入庫的時候，插入異常，log4j記錄下大量的異常日誌，其中主要的就是這個JSON引數資訊。今天看昨天的log4j的日誌檔案，從18：02開始第一次定時任務，到今天凌晨，日誌檔案達到了348M。

而今天凌晨開始的產生的日誌檔案更是誇張，日誌大小達到了2.7G。

而今天的日誌檔案，EditPlus根本打不開，用了一個大檔案工具檢視，全是這個統計結果的JSON資訊。再加上其他的異常資訊，累計就到了這個級別了。還真嚇倒我了，從來沒有見到過這麼大的日誌量。

定時任務並行問題

由於開始用的是Quartz的並行定時任務，每隔5分鐘一次，但是一次耗時40分鐘的任務，導致Quartzs的工作執行緒很快就被這一個型別的定時任務佔滿了，其他正常任務就無法執行了。

解決辦法，將這個定時任務設定成不能並行的，必須等上一次任務執行完成後再進行下一次任務。其實Quartz提供了StatefulJob介面，它被廢棄了，被註解@DisallowConcurrentExecution替代。只要這樣一行程式碼就可以讓它們順次執行了。

但是，我用了一個笨方法，用Java的執行緒池的scheduleAtFixedRate方法，多寫了至少30行程式碼，這點，我不能釋懷，腦子再靈活一點搜一下Quartz的非並行任務就好了。

統計伴隨的高CPU消耗

再說說這個統計過程吧，由於Sequoiadb的聚集操作相當耗時，所以採用的是逐條遍歷原始流量資料，然後用Java的Map和List進行統計處理方式。

現實場景下，源和目的IP量大且組合總量眾多，統計操作裡面的Map和List將需要頻繁擴容，而我初始化的Map的容量是128，而真實的源IP個數為一萬多個，那麼這麼Map的擴容會相當頻繁；其次，就是每個源IP的目的IP情況，初始化為64，而真實的目的IP也有一千多個，那麼也會頻繁擴容。

這樣就出現了一種現象：每次該任務執行時，過一會就開始出現好幾個高CPU消耗的執行緒，而且執行緒ID相互挨著：

打出堆疊日誌，除了第一個是這個統計任務執行緒，其他高CPU消耗的執行緒都是JVM的GC執行緒。

降低GC消耗，採取的方式是：修改JVM引數，因為原來的tomcat的啟動引數配置的xmx為512M，太小了，目標伺服器的記憶體是32G，所以這可能是導致GC頻繁的原因。稍微調大到2G後，這種現象消失。

JAVA_OPTS=”-server -Xms512m -Xmx2048m -XX:PermSize=512M -XX:MaxPermSize=512m”

啟示錄

那個2.7G的日誌檔案，VPN傳送了一上午只傳了76%就終止了。用打檔案開啟工具，逐行滾動，檢視它的內容，結果發現，全是統計JSON，終於知道這個大日誌是怎麼回事了。

這樣一個大檔案，直接用vi開啟，黑屏上全是閃爍的01形象，看得人眼暈。還好，我夠有耐心，混跡於1048576的世界裡，我依舊只有一個感受：程式設計路漫漫，我還在路上。

備註：偶然發現1048576，這個數字串是如此的有趣，1024*1024=1024K。