通过 syslog 发送 log4j2 堆栈跟踪

Posted

技术标签:

【中文标题】通过 syslog 发送 log4j2 堆栈跟踪【英文标题】：Send log4j2 stack traces over syslog 【发布时间】：2016-11-08 12:18:51 【问题描述】：

我正在尝试将堆栈跟踪记录到 Logstash。

日志堆栈是 ELK（ElasticSearch、Logstash、Kibana）。

产生日志的应用是一个Java应用，使用slf4j作为日志接口，log4j2作为日志实现。

log4j2.xml 以RFC5424 格式声明此syslog Appender：

<Appenders>
  <Syslog name="RFC5424" format="RFC5424" host="localhost" port="8514"
          protocol="TCP" appName="MyApp" includeMDC="true" mdcId="mdc"
          facility="LOCAL0" enterpriseNumber="18060" newLine="true"
          messageId="Audit" id="App">
    <LoggerFields>
      <KeyValuePair key="thread" value="%t"/>
      <KeyValuePair key="priority" value="%p"/>
      <KeyValuePair key="category" value="%c"/>
      <KeyValuePair key="exception" value="%exfull"/>
    </LoggerFields>
  </Syslog>
</Appenders>

我从 Java 应用程序中记录一个 Throwable，如下所示：

org.slf4j.LoggerFactory.getLogger("exception_test").error("Testing errors", new RuntimeException("Exception message"));

当记录异常时，Logstash 会跟踪类似这样的内容，以向我展示它持续存在的内容：


   "@timestamp":"2016-11-08T11:08:10.387Z",
   "port":60397,
   "@version":"1",
   "host":"127.0.0.1",
   "message":"<131>1 2016-11-08T11:08:10.386Z MyComputer.local MyApp - Audit [mdc@18060 category=\"exception_test\" exception=\"java.lang.RuntimeException: Exception message",
   "type":"syslog",
   "tags":[
      "_grokparsefailure"
   ]

我确认 Kibana 在其日志条目之一的 _source 字段中显示完全相同的 JSON。

这里有一个问题：没有保存堆栈跟踪。并且“测试错误”消息丢失了。

"tags":["_grokparsefailure"] 很不幸，但 与这个问题无关。

我尝试添加&lt;ExceptionPattern/&gt; 看看它是否会改变任何东西：

<Syslog name="RFC5424" format="RFC5424" host="localhost" port="8514"
        protocol="TCP" appName="MyApp" includeMDC="true" mdcId="mdc"
        facility="LOCAL0" enterpriseNumber="18060" newLine="true"
        messageId="Audit" id="App">
  <LoggerFields>
    <KeyValuePair key="thread" value="%t"/>
    <KeyValuePair key="priority" value="%p"/>
    <KeyValuePair key="category" value="%c"/>
    <KeyValuePair key="exception" value="%exfull"/>
  </LoggerFields>
  <ExceptionPattern>%exfull</ExceptionPattern>
</Syslog>

&lt;ExceptionPattern/&gt; 替换了日志消息，也（遗憾地）省略了所有 loggerFields。但它确实给了我一个类名和行号：


   "@timestamp":"2016-11-08T11:54:03.835Z",
   "port":60397,
   "@version":"1",
   "host":"127.0.0.1",
   "message":"at com.***.LogTest.throw(LogTest.java:149)",
   "type":"syslog",
   "tags":[
      "_grokparsefailure"
   ]

再次：没有堆栈跟踪。再说一遍：“测试错误”消息丢失了。

如何使用log4j2 将堆栈跟踪记录到 Logstash？我不一定非得使用syslog appender。

基本上限制是：

不被锁定到任何特定的日志记录基础设施（这就是我使用 syslog 的原因） 多行堆栈跟踪需要被理解为单个日志条目。 “堆栈跟踪的每一行”都是“单独的日志消息”是不可取的 堆栈跟踪必须能够接受过滤器。我的一个典型例外可能有一个页面长的堆栈跟踪。我想过滤掉像 Spring 这样的框架。

【问题讨论】：

【参考方案1】：

Log4j 2.5 的 SyslogAppender 只能通过 UDP 发送堆栈跟踪。

<Syslog name="RFC5424" format="RFC5424" host="localhost" port="8514"
        protocol="UDP" appName="MyApp" includeMDC="true" mdcId="mdc"
        facility="LOCAL0" enterpriseNumber="18060" newLine="true"
        messageId="LogTest" id="App">
  <LoggerFields>
    <KeyValuePair key="thread" value="%t"/>
    <KeyValuePair key="priority" value="%p"/>
    <KeyValuePair key="category" value="%c"/>
    <KeyValuePair key="exception" value="%exfull"/>
  </LoggerFields>
  <ExceptionPattern>%exfull</ExceptionPattern>
</Syslog>

使用 UDP：ExceptionPattern 和 LoggerFields.KeyValuePair["exception"] 都开始作为多行堆栈跟踪的解决方案。

这是logstash 在我通过 syslog 通过 UDP 发送异常时打印的内容：


    "@timestamp" => 2016-11-14T13:23:38.304Z,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "<131>1 2016-11-14T13:23:38.302Z BirchBox.local MyApp - LogTest [mdc@18060 category=\"com.***.Deeply\" exception=\"java.lang.RuntimeException: Exception message\n\tat com.***.Deeply.complain(Deeply.java:10)\n\tat com.***.Nested.complain(Nested.java:8)\n\tat com.***.Main.main(Main.java:20)\n\" priority=\"ERROR\" thread=\"main\"] Example error\njava.lang.RuntimeException: Exception message\n\tat com.***.Deeply.complain(Deeply.java:10)\n\tat com.***.Nested.complain(Nested.java:8)\n\tat com.***.Main.main(Main.java:20)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]

在[mdc@18060 exception=\"…\"] 中，我们得到LoggerFields.KeyValuePair["exception"] 堆栈跟踪。

除此之外：感谢ExceptionPattern，堆栈跟踪被插入到记录的消息本身中。

供参考：这是logstash 通过 syslog 通过 TCP 发送异常时打印的内容（即与上述相同的 SyslogAppender，但使用 protocol="TCP" 代替）：


    "@timestamp" => 2016-11-14T19:56:30.293Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "<131>1 2016-11-14T19:56:30.277Z BirchBox.local MyApp - Audit [mdc@18060 category=\"com.***.Deeply\" exception=\"java.lang.RuntimeException: Exception message",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.296Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Deeply.complain(Deeply.java:10)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.296Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Nested.complain(Nested.java:8)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.296Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Main.main(Main.java:20)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.296Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "\" priority=\"ERROR\" thread=\"main\"] Example error",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.296Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "java.lang.RuntimeException: Exception message",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.297Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Deeply.complain(Deeply.java:10)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.298Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Nested.complain(Nested.java:8)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.298Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "at com.***.Main.main(Main.java:20)",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]


    "@timestamp" => 2016-11-14T19:56:30.299Z,
          "port" => 63179,
      "@version" => "1",
          "host" => "127.0.0.1",
       "message" => "",
          "type" => "syslog",
          "tags" => [
        [0] "_grokparsefailure"
    ]

看起来 TCP 确实“工作”了，但将单个日志消息拆分为 许多 syslog 消息（例如当遇到 \n 时）。

【讨论】：

我在 Syslog appender 中使用 PatternLayout，并且“%throwableseparator(|)”允许我通过 TCP 获取整个异常堆栈。

以上是关于通过 syslog 发送 log4j2 堆栈跟踪的主要内容，如果未能解决你的问题，请参考以下文章

log4j2 syslog 数据报大小超过 UDP 的限制

如何让 log4j syslog appender 在一行中写入堆栈跟踪？

Mac 上的 Log4j2 Syslog Appender 格式

log4j2 - Syslog 附加程序和 PatternLayout

Log4j2 Syslog Appender 添加垃圾字段

将 Apache Storm Log4j2 syslog appender 从 UDP 更改为 TCP