1. 程式人生 > >程式中的日誌

程式中的日誌

目錄

  • 程式中的日誌
    • 日誌概念和分類
      • 應用程式中的日誌
      • 資料庫中的日誌
      • 分散式系統中的日誌
    • 日誌結構設計
    • 日誌能做什麼事情
      • 線上日誌排錯
      • 藉助 ELK,GreyLog 等第三方工具監控程式
      • 藉助FileBeat,Flume等工具自定義日誌收集
    • 日誌該怎麼列印
      • 什麼時候應該打日誌
      • 基本格式
    • jvm 動態除錯
    • 參考資料

程式中的日誌

日誌實際上只是一種按照時間順序儲存記錄的資料表或檔案
它記錄了什麼時間發生了什麼事情。而對分散式資料系統,在許多方面,這是要解決的問題的真正核心

日誌概念和分類

應用程式中的日誌

tomcat 日誌

資料庫中的日誌

日誌記錄了發生了什麼,而每個表或者索引都是更改歷史中的一個投影。由於日誌是立即持久化的,發生崩潰時,可以作為恢復其他所有持久化結構的可靠來源

機器可識別的日誌的概念主要都被侷限在資料庫的內部。日誌作為做資料訂閱機制的用法似乎是偶然出現的。 但這正是支援各種的訊息傳輸、資料流和實時資料處理的理想抽象

分散式系統中的日誌

分散式系統以日誌為中心的方案是來自於一個簡單的觀察,我們稱之為狀態機複製原理(State Machine Replication Principle):

如果兩個相同的、確定性的程序從同一狀態開始,並且以相同的順序獲得相同的輸入,那麼這兩個程序將會生成相同的輸出,並且結束在相同的狀態

確定性(deterministic)
和冪等概念類似,同樣的輸入,任何情況都得到同樣的輸出
意味著處理過程是與時間無關的,而且不會讓任何其他『帶外』輸入("out of band" input)影響其處理結果

舉例:
我們甚至可以記錄各個副本執行的機器指令序列的日誌 或是 所呼叫的方法名和引數序列的日誌。 只要兩個程序用相同的方式處理這些輸入,這些副本程序就會保持一致的狀態。

物理與邏輯日誌
對日誌用法不同群體有不同的說法。資料庫工作者通常說成 物理 日誌(physical logging)和 邏輯 日誌(logical logging)。 物理日誌是指記錄每一行被改變的內容。邏輯日誌記錄的不是改變的行而是那些引起行的內容改變的SQL語句(insert、update和delete語句)

狀態機器模型
分散式系統文獻通常把處理和複製(processing and replication)方案寬泛地分成兩種。『狀態機器模型』

『主-主模型』(active-active model), 記錄輸入請求的日誌,各個複本處理每個請求。
『主-備模型』(primary-backup model),即選出一個副本做為leader,讓leader按請求到達的順序處理請求,並輸出它請求處理的狀態變化日誌。 其他的副本按照順序應用leader的狀態變化日誌,保持和leader同步,並能夠在leader失敗的時候接替它成為leader。

變更日誌(changelog)101:表與事件的二象性(duality)

變更的日誌 和 表之間有著迷人的二象性。 日誌類似借貸清單和銀行處理流水,而資料庫表則是當前賬戶的餘額。如果有變更日誌,你就可以應用這些變更生成資料表並得到當前狀態

可以認識到日誌是更基本的資料結構:日誌除了可用來建立原表,也可以用來建立各類衍生表
表與事件的二象性: 表支援了靜態資料,而日誌記錄了變更。日誌的魅力就在於它是變更的 完整 記錄,它不僅僅包含了表的最終版本的內容, 而且可以用於重建任何存在過其它版本。事實上,日誌可以看作是表 每個 歷史狀態的一系列備份

表與事件是資料在不同條件/場景下資料的性質,是對人們對資料的認識、理解或描述方式。

版本控制系統通過日誌來完成複製:更新程式碼即是拉下補丁並應用到你的當前快照中。

日誌結構設計

這塊沒有總結出一個完成的定義,還是把各種實現方式帶給大家,讓大家來理解看看大家有沒有其他的更好的理解和建議

OpenTracing語義標準規範及實現
https://www.jianshu.com/p/a963ad0bbe3e

如何使用 AOP 和自定義註解實現請求方法前後日誌列印
https://mp.weixin.qq.com/s/J9eyqIx5Oq-z6mYv8j1zpg

在SpringBoot專案中新增logback的MDC
(Mapped Diagnostic Context,用於打LOG時跟蹤一個“會話“、一個”事務“)
https://blog.csdn.net/hongyang321/article/details/78803584

服務端最佳日誌實踐(v2.0)
https://zhuanlan.zhihu.com/p/27363484

基於elk的業務日誌格式設計
https://segmentfault.com/a/1190000008227989

跟蹤日誌,程式日誌,操作日誌
http://dev.bingocc.com/dtls/logs/prog.html

{
    "type": 
    "trace_id":
    "span_id":
    "thread":
    "timestamp":
    "source_host":
    "component":    
    "logs": [
        {"LogItem":"LogItem"}
    ]
}

LogItem

{
    "level":
    "thread":
    "timestamp":
    "logger":    
    "message":
    "stack":
    "tags": {
    }
}

日誌能做什麼事情

線上日誌排錯

我們平常使用的 tail -f xxx.log 的形式,來動態觀察錯誤,除錯程式

藉助 ELK,GreyLog 等第三方工具監控程式

方便檢視
使用這類工具依賴可以有web介面來檢視log,使用起來更友好,搜尋條件,無需熟悉linux命令,即可快速的查詢指定時間段的log或是包含指定關鍵字的log

聚類分析
elk 和 grey log都有一點分析圖表和監控報警功能,都可以幫忙實現應用監控指標分析和報警

藉助FileBeat,Flume等工具自定義日誌收集

自定義日誌收集處理
服務端接收到格式化的日誌log,對log進行業務分析和統計,對程式狀態,應用使用,業務狀態進行分析,並能對突發情況作出預警和響應緊急措施

一段nginx log示例
-- 01 online-php7-6 2018-04-20T12:00:00+08:00 2018-04-20T12:00:00+08:00 0 web 34055 272408431 read_article {"novel_id":"2460","article_id":"883878","price":"35","consume":0}

各個欄位含義
-- version, hostname, occur_time, log_time, type, platform, user_id, action, action_json

version: 01
hostname: online-php7-6 hostname
occur_time: 2018-04-20T12:00:00+08:00
log_time: 2018-04-20T12:00:00+08:00
platform: web
user_id: 367245568
action: read_article {"novel_id":"1542","article_id":"672651","price":"35","consume":1}

業務含義
根據上述的列印方式可以追蹤到app內部每個模組業務被觸發的頻次,這只是處理了業務這一範圍,其實還可以有很多範圍比如:關鍵業務路徑範圍業務異常警告報錯範圍 等等,一切圍繞應用的日誌

日誌該怎麼列印

什麼時候應該打日誌

  1. 當你遇到問題的時候,只能通過debug功能來確定問題,你應該考慮打日誌,良好的系統,是可以通過日誌進行問題定為的。

  2. 當你碰到if…else 或者 switch這樣的分支時,要在分支的首行列印日誌,用來確定進入了哪個分支

  3. 經常以功能為核心進行開發,你應該在提交程式碼前,可以確定通過日誌可以看到整個流程

基本格式

必須使用引數化資訊的方式:

logger.debug("Processing trade with id:[{}] and symbol : [{}] ", id, symbol);

對於debug日誌,必須判斷是否為debug級別後,才進行使用:

if (logger.isDebugEnabled()) {
    logger.debug("Processing trade with id: " +id + " symbol: " + symbol);
}

使用[]進行引數變數隔離

logger.debug("Processing trade with id:[{}] and symbol : [{}] ", id, symbol);

並不是所有的service都進行出入口打點記錄,單一、簡單service是沒有意義的(job除外,job需要記錄開始和結束,)。
反例(不要這麼做):

public List listByBaseType(Integer baseTypeId) {


   log.info("開始查詢基地");
BaseExample ex=new BaseExample();
BaseExample.Criteria ctr = ex.createCriteria();
ctr.andIsDeleteEqualTo(IsDelete.USE.getValue());
Optionals.doIfPresent(baseTypeId, ctr::andBaseTypeIdEqualTo);
   log.info("查詢基地結束");
return baseRepository.selectByExample(ex);


}

對於複雜的業務邏輯,需要進行日誌打點,以及埋點記錄,比如電商系統中的下訂單邏輯,以及OrderAction操作(業務狀態變更)

重要的狀態的變更傳送事件並留出監聽介面,這個主題下含義是至少要列印log

service為SOA架構,微服務架構,REST介面,那麼可以看成是一個外部介面提供方,那麼必須記錄入參。

呼叫其他第三方服務時,所有的出參和入參是必須要記錄的(因為你很難追溯第三方模組發生的問題)

特別詳細的系統執行完成資訊,業務程式碼中,不要使用.(除非有特殊用意,否則請使用DEBUG級別替代)

@Override
@Transactional
public void createUserAndBindMobile(@NotBlank String mobile, @NotNull User user) throws CreateConflictException{
    boolean debug = log.isDebugEnabled();
    if(debug){
        log.debug("開始建立使用者並繫結手機號. args[mobile=[{}],user=[{}]]", mobile, LogObjects.toString(user));
    }
    try {
        user.setCreateTime(new Date());
        user.setUpdateTime(new Date());
        userRepository.insertSelective(user);
        if(debug){
            log.debug("建立使用者資訊成功. insertedUser=[{}]",LogObjects.toString(user));
        }
        UserMobileRelationship relationship = new UserMobileRelationship();
        relationship.setMobile(mobile);
        relationship.setOpenId(user.getOpenId());
        relationship.setCreateTime(new Date());
        relationship.setUpdateTime(new Date());
        userMobileRelationshipRepository.insertOnDuplicateKey(relationship);
        if(debug){
            log.debug("繫結手機成功. relationship=[{}]",LogObjects.toString(relationship));
        }
        log.info("建立使用者並繫結手機號. userId=[{}],openId=[{}],mobile=[{}]",user.getId(),user.getOpenId(),mobile); 
        // 如果考慮安全,手機號記得脫敏
    }catch(DuplicateKeyException e){
        log.info("建立使用者並繫結手機號失敗,已存在相同的使用者. openId=[{}],mobile=[{}]",user.getOpenId(),mobile);
        throw new CreateConflictException("建立使用者發生衝突, openid=[%s]",user.getOpenId());
    }
}

jvm 動態除錯

日誌列印一般都是,程式碼寫好後部署上去的,忘記加的需要重新編寫然後重啟發布,這塊其實也有熱部署的方案

這塊其實更側重於線上除錯,不過都是定位問題,也可以放在日誌範疇來討論,動態替換程式碼,加入日誌列印程式碼,重新使用classloader加入記憶體

BTrace
這個偷懶貼了兩篇帖子
https://tech.meituan.com/2019/02/28/java-dynamic-trace.html
https://www.ezlippi.com/blog/2018/01/btrace-introduce.html

arthas 同樣可以動態列印追蹤
使用redefine動態修改程式碼,加入log列印然後在重新編譯會classloader
https://alibaba.github.io/arthas/
https://alibaba.github.io/arthas/redefine.html

參考資料

Logging 日誌記錄最佳實踐
https://www.oschina.net/question/12_44624

Logging 最佳實踐
https://www.cnblogs.com/zhengyun_ustc/archive/2012/12/15/logging_bp.html

OpenTracing語義標準規範及實現
https://www.jianshu.com/p/a963ad0bbe3e

統一日誌服務系統架構
http://dev.bingocc.com/dtls/arch.html

原來這才是日誌列印的正確姿勢
https://blog.csdn.net/u013256816/article/details/94518764

一些設計上的基本常識

https://gitee.com/52itstyle/spring-boot-seckill/blob/master/%E6%9E%B6%E6%9E%84%E4%B9%8B%E8%B7%AF/%E4%B8%80%E4%BA%9B%E8%AE%BE%E8%AE%A1%E4%B8%8A%E7%9A%84%E5%9F%BA%E6%9C%AC%E5%B8%B8%E8%AF%86%20-%20%E6%A2%81%E9%A3%9E.md#

日誌:每個軟體工程師都應該知道的有關實時資料的統一抽象
https://github.com/oldratlee/translations/tree/master/log-what-every-software-engineer-should-know-about-real-time-datas-unif