多行日志（例如異常信息）為調(diào)試應(yīng)用問題提供了許多非常有價值的信息，在分布式微服務(wù)流行的今天基本上都會統(tǒng)一將日志進行收集，比如常見的 ELK、EFK 等方案，但是這些方案如果沒有適當(dāng)?shù)呐渲?，它們是不會將多行日志看成一個整體的，而是每一行都看成獨立的一行日志進行處理，這對我們來說是難以接受的。

在本文中，我們將介紹一些常用日志收集工具處理多行日志的策略。

1JSON

保證多行日志作為單個事件進行處理最簡單的方法就是以 JSON 格式記錄日志，比如下面是常規(guī) Java 日常日志的示例： 

# javaApp.log  
2019-08-14 14:51:22,299 ERROR [http-nio-8080-exec-8] classOne: Index out of range  
java.lang.StringIndexOutOfBoundsException: String index out of range: 18  
 at java.lang.String.charAt(String.java:658)  
 at com.example.app.loggingApp.classOne.getResult(classOne.java:15)  
 at com.example.app.loggingApp.AppController.tester(AppController.java:27)  
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)  
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)  
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)  
 at java.lang.reflect.Method.invoke(Method.java:498)  
 at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)  
 at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)  
[...] 

如果直接收集上面的日志會識別為多行日志，如果我們用 JSON 格式來記錄這些日志，然后介紹 JSON 的數(shù)據(jù)就簡單多了，比如使用 Log4J2 來記錄，變成下面的格式： 

{"@timestamp":"2019-08-14T18:46:04.449+00:00","@version":"1","message":"Index out of range","logger_name":"com.example.app.loggingApp.classOne","thread_name":"http-nio-5000-exec-6","level":"ERROR","level_value":40000,"stack_trace":"java.lang.StringIndexOutOfBoundsException: String index out of range: 18\n\tat java.lang.String.charAt(String.java:658)\n\tat com.example.app.loggingApp.classOne.getResult(classOne.java:15)\n\tat com.example.app.loggingApp.AppController.tester(AppController.java:27)\n\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)\n\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tat java.lang.reflect.Method.invoke(Method.java:498)\n\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)\n\tat 
[...]  
} 

 這樣整個日志消息都包含在單個 JSON 對象匯總了，其中就包含完整的異常堆棧信息，絕大多數(shù)工具都支持直接解析 JSON 日志數(shù)據(jù)，這是最簡單的一種方法，對于運維同學(xué)來說也是最省心的，但是大部分開發(fā)人員是抵觸用 JSON 格式來記錄日志的~~~

2Logstash

對于使用 Logstash 的用戶來說，要支持多行日志也不困難，Logstash 可以使用插件解析多行日志，該插件在日志管道的 input 部分進行配置。例如，下面的配置表示讓 Logstash 匹配你的日志文件中 ISO8601 格式的時間戳，當(dāng)匹配到這個時間戳的時候，它就會將之前所有不以時間戳開頭的內(nèi)容折疊到之前的日志條目中去。 

input {  
  file {  
    path => "/var/app/current/logs/javaApp.log"  
    mode => "tail"  
    codec => multiline {  
      pattern => "^%{TIMESTAMP_ISO8601} "  
      negate => true  
      what => "previous"  
    }  
  }  
} 

3Fluentd

和 Logstash 類似，F(xiàn)luentd 也允許我們使用一個插件來處理多行日志，我們可以配置插件接收一個或多個正則表達式，以下面的 Python 多行日志為例： 

2019-08-01 18:58:05,898 ERROR:Exception on main handler  
Traceback (most recent call last):  
  File "python-logger.py", line 9, in make_log  
    return word[13]  
IndexError: string index out of range 

如果沒有 multiline 多行解析器，F(xiàn)luentd 會把每行當(dāng)成一條完整的日志，我們可以在 <source> 模塊中添加一個 multiline 的解析規(guī)則，必須包含一個 format_firstline 的參數(shù)來指定一個新的日志條目是以什么開頭的，此外還可以使用正則分組和捕獲來解析日志中的屬性，如下配置所示： 

<source>  
  @type tail  
  path /path/to/pythonApp.log  
  tag sample.tag  
  <parse>  
    @type multiline  
    format_firstline /\d{4}-\d{1,2}-\d{1,2}/  
    format1 /(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+:)(?<message>[\s\S]*)/  
  </parse>  
</source> 

在解析部分我們使用 @type multiline 指定了多行解析器，然后使用 format_firstline 來指定我們多行日志開頭的規(guī)則，這里我們就用一個簡單的正則匹配日期，然后指定了其他部分的匹配模式，并為它們分配了標(biāo)簽，這里我們將日志拆分成了 timestamp、level、message 這幾個字段。

經(jīng)過上面的規(guī)則解析過后，現(xiàn)在 Fluentd 會將每個 traceback 日志看成一條單一的日志了： 

{  
  "timestamp": "2019-08-01 19:22:14,196",  
  "level": "ERROR:",  
  "message": "Exception on main handler\nTraceback (most recent call last):\n  File \"python-logger.py\", line 9, in make_log\n    return word[13]\nIndexError: string index out of range" 
 } 

該日志已被格式化為 JSON，我們匹配的標(biāo)簽也被設(shè)置為了 Key。

在 Fluentd 官方文檔中也有幾個示例說明：

•  Rails 日志

比如輸入的 Rails 日志如下所示： 

Started GET "/users/123/" for 127.0.0.1 at 2013-06-14 12:00:11 +0900  
Processing by UsersController#show as HTML  
  Parameters: {"user_id"=>"123"}  
  Rendered users/show.html.erb within layouts/application (0.3ms)  
Completed 200 OK in 4ms (Views: 3.2ms | ActiveRecord: 0.0ms) 

我們可以使用下面的解析配置進行多行匹配： 

<parse>  
  @type multiline  
  format_firstline /^Started/  
  format1 /Started (?<method>[^ ]+) "(?<path>[^"]+)" for (?<host>[^ ]+) at (?<time>[^ ]+ [^ ]+ [^ ]+)\n/  
  format2 /Processing by (?<controller>[^\u0023]+)\u0023(?<controller_method>[^ ]+) as (?<format>[^ ]+?)\n/  
  format3 /(  Parameters: (?<parameters>[^ ]+)\n)?/  
  format4 /  Rendered (?<template>[^ ]+) within (?<layout>.+) \([\d\.]+ms\)\n/  
  format5 /Completed (?<code>[^ ]+) [^ ]+ in (?<runtime>[\d\.]+)ms \(Views: (?<view_runtime>[\d\.]+)ms \| ActiveRecord: (?<ar_runtime>[\d\.]+)ms\)/  
</parse> 

解析過后得到的日志如下所示： 

{  
  "method"           :"GET",  
  "path"             :"/users/123/",  
  "host"             :"127.0.0.1",  
  "controller"       :"UsersController",  
  "controller_method":"show",  
  "format"           :"HTML",  
  "parameters"       :"{ \"user_id\":\"123\"}",  
  ...  
} 

•     Java 堆棧日志

比如現(xiàn)在我們要解析的日志如下所示： 

2013-3-03 14:27:33 [main] INFO  Main - Start  
2013-3-03 14:27:33 [main] ERROR Main - Exception  
javax.management.RuntimeErrorException: null  
    at Main.main(Main.java:16) ~[bin/:na] 
2013-3-03 14:27:33 [main] INFO  Main - End 

則我們可以使用下面的解析規(guī)則進行多行匹配： 

<parse>  
  @type multiline  
  format_firstline /\d{4}-\d{1,2}-\d{1,2}/  
  format1 /^(?<time>\d{4}-\d{1,2}-\d{1,2} \d{1,2}:\d{1,2}:\d{1,2}) \[(?<thread>.*)\] (?<level>[^\s]+)(?<message>.*)/  
</parse> 

解析過后的日志為： 

{  
  "thread" :"main",  
  "level"  :"INFO",  
  "message":"  Main - Start"  
}  
{  
  "thread" :"main",  
  "level"  :"ERROR",  
  "message":" Main - Exception\njavax.management.RuntimeErrorException: null\n    at Main.main(Main.java:16) ~[bin/:na]"  
}  
{  
  "thread" :"main",  
  "level"  :"INFO",  
  "message":"  Main - End"  
} 

上面的多行解析配置中除了 format_firstline 指定多行日志的開始行匹配之外，還用到了 format1、format2…formatN 這樣的配置，其中 N 的范圍是 1...20，是多行日志的 Regexp 格式列表，為了便于配對，可以將 Regexp 模式分割成多個 regexpN 參數(shù)，將這些匹配模式連接起來構(gòu)造出多行模式的正則匹配。

4Fluent Bit

Fluent Bit 的 tail input 插件也提供了處理多行日志的配置選項，比如現(xiàn)在我們還是來處理之前的 Python 多行日志： 

2019-08-01 18:58:05,898 ERROR:Exception on main handler  
Traceback (most recent call last):  
  File "python-logger.py", line 9, in make_log  
    return word[13]  
IndexError: string index out of range 

如果不用多行解析器 Fluent Bit 同樣會將每一行當(dāng)成一條日志進行處理，我們可以配置使用 Fluent Bit 內(nèi)置的 regex 解析器插件來結(jié)構(gòu)化多行日志： 

[PARSER]  
     Name         log_date  
     Format       regex  
     Regex        /\d{4}-\d{1,2}-\d{1,2}/  
 [PARSER]  
     Name        log_attributes  
     Format      regex  
     Regex       /(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+:)(?<message>[\s\S]*)/  
  [INPUT]  
     Name              tail  
     tag               sample.tag  
     path              /path/to/pythonApp.log  
     Multiline         On  
     Parser_Firstline  log_date  
     Parser_1          log_attributes 

和 Fluentd 類似，Parser_Firstline 參數(shù)指定了與多行日志開頭相匹配的解析器的名稱，當(dāng)然我們也可以包含額外的解析器來進一步結(jié)構(gòu)化你的日志。這里我們配置了首先使用 Parser_Firstline 參數(shù)來匹配 ISO8601 日期開頭的日志行，然后使用 Parser_1 參數(shù)來指定匹配模式，以匹配日志消息的其余部分，并為它們分配了 timestamp、level、message 標(biāo)簽。

最終轉(zhuǎn)換過后我們的日志變成了如下所示的格式： 

{  
  "timestamp": "2019-08-01 19:22:14,196",  
  "level": "ERROR:",  
  "message": "Exception on main handler\nTraceback (most recent call last):\n  File \"python-logger.py\", line 9, in make_log\n    return word[13]\nIndexError: string index out of range" 
}