實現 5.0 create ilo ask 內存空間 更多 一個 大於

1.前言

　　在日常工作中，我們常常會遇到隨著業務的發展，系統的性能逐漸無法滿足業務需求，這個時候就需要系統進行技術改造或者性能調優。技改可能會包括系統的重構甚至重寫，功能的重新劃分，但是只要是找了性能的瓶頸點，也許只是一些jvm參數或者常量的調優。

2.優化

　　為了尋找系統的性能瓶頸點，如果有一套完整圖形化的監控系統固然是好事，但是很多情況都可能無法滿足這個要求，更多的是通過日誌來完成。因此，在合理的地方打印日誌尤為重要。

　　上周某日下午，一個線上系統開始打印大量錯誤日誌，查看日誌發現錯誤基本為數據庫唯一鍵沖突，通過分析發現日誌發現該系統（下面以系統A稱呼）的獎勵發放功能在上一個獎罰發放還沒有完成的情況下，又觸發了新的獎勵發放調用，獎勵發放未半小時觸發一次。因為獎勵發放邏輯沒有做並發同步處理，導致數據落庫的時候發生唯一鍵沖突。因為是離線發放邏輯不考慮實時性，而且當前的數據量可以通過單機多線程並發處理，所以一方面通過redis鎖保證同一時間只有一個獎勵發放在處理，另一方面通過進行系統優化，盡可能的降低一次獎勵發放的耗時。

　　系統A的處理邏輯為，系統A會定時收到系統B的調用，一次消息代表一次獎勵發放任務，一次任務包含多個司機，需要分別對多個司機進行獎勵發放。基本的處理邏輯是系統A在被調用後，獲取任務所需基本信息，分批獲取相關司機，多線程執行發放任務，每一次submit任務後都會sleep50毫秒，最後通過countdown同步等待異步任務處理完成，在整個任務的開始和結束的時候都會打印日誌。為了確認單個任務的耗時，實現了下面的wrapper類

public class MarketingRunnableWrapper implements Runnable {
    private static final ILog logger = LogFactory.getLog("threadLogger");
    
 
//任務名
    private String            taskName;
    //任務創建時間
    private Long              taskCreateTime;
    //日誌flag
    private String            flag;
　　
　　 private Runnable runnable;


    public MarketingRunnableWrapper(Runnable runnable) {
        this(runnable, "");
    }

    public MarketingRunnableWrapper(Runnable runnable, String taskName) {
        this
 
.runnable = runnable;this.taskName = taskName;
        this.taskCreateTime = System.nanoTime();
        this.flag = LogFactory.getFlag();
    }

    @Override
    public void run() {
        Long beginTime = System.nanoTime();
        try {
            runnable.run();
        } catch (Exception e) {
            String msg = "task: " + taskName + " run throw exception";
            msgLog(msg, e);
        } finally {
            String msg = String.format(
                    "task: %s executed, thread name = %s, delay time = %s ms, executing time = %s ms", taskName,
                    Thread.currentThread().getName(), (beginTime - taskCreateTime) / 1000000,
                    (System.nanoTime() - beginTime) / 1000000);
            msgLog(msg, null);
        }
    }

    private void msgLog(String msg, Exception e) {
        LogFactory.setFlag(flag);
        if (e == null) {
            logger.info(msg);
        } else {
            logger.error(msg, e);
        }
        LogFactory.removeFlag();
    }
}

　　該wrapper類實現了Runnable接口，打印一次task的執行的等待耗時和執行耗時。

　　根據日誌打印和程序常量得到如下數據表：

	總耗時 Ttotal（s）	任務數Nt	總耗時 Ttotal/任務數Nt(ms)	任務總耗時Ttt（ms，相加耗時）	平均Taver/最大任務耗時Tmax（ms）	核心Ntcore/最大線程數Ntm	平均Taver/核心Ntcore(ms)
任務獎勵(獎勵)	126.000	2437	51.72	27344	11.22/43	10/10(公用)	1.1

　　

　　上述表格中Ttt和Taver、Tmax都是從單線程的角度來說明的

1. 數據計算

　　　　任務添加等待時長Tw = 50ms 　　　　如果滿線程跑的話，平均單個任務執行實際耗時Tstrt = Taver/Ntcore = 1.1ms 　　　　Tw遠遠大於Tstrt說明，基本只有一個線程在跑，而且還是跑跑停停，沒有發揮多線程的優勢

2. 分析

　　　　因為Twt大於Tstrt，說明添加等待限制了線程池的性能 　　　　平均每個任務執行實際耗時Trorign = Ttotal/Nt = 126000/2437 = 51.72ms ~ Tw(這也說明主要花在了等待上面)

3. 優化方案

　　　　將等待時間Tw修改為5ms 　　等待時間優化後，數據如下：

	總耗時 Ttotal（s）	任務數Nt	實際平均任務耗時Trtapt (總耗時 Ttotal/任務數Nt(ms))	Tw	任務總耗時Ttt（ms，相加耗時）	平均Taver/最大任務耗時Tmax（ms）	核心Ntcore/最大線程數Ntm	理論平均任務耗時Tctapt (平均Taver/核心Ntcore(ms))
任務獎勵(獎勵)	415.088	36259	11.5	10	1253473	34.56/147	10/10(公用)	3.5

　　 　　從上面這個表可以看出Trtapt比Tctapt大，但是與Tw相近，說明現在主要的耗時還是由Tw，任務插入等待決定，所以還有一定的優化空間，但是相比之前的的吞吐量，提高了接近五倍。 　　那是否可以去掉插入等待的時間，直接將任務插入到隊列中呢。由於為了保證內存空間不會OOM，一般會設置一個相對合理的隊列長度，這樣的話就是需要保證隊列長度足夠長，使得任務可以大批量的插入而不會block，或者設置合理的隊列滿的處理邏輯，而且較大的隊列長度存在對內存空間的壓力以及fullgc的風險。因此設置一個合理的任務插入等待時間和一個合理的隊列長度（不用太大），可以保證相對較高的吞吐量。

我們該怎麽結合日誌做優化