log4j syslogappender堆栈跟踪输出不在同一行

Question

我正在尝试使用log4j和rsyslog进行集中式日志记录.

到目前为止我有什么

Solr在RHEL6上的tomcat6内运行,使用以下log4j和sl4j库

# lsof -u tomcat | grep log4j
java    14503 tomcat  mem    REG              253,0      9711    10208 /usr/share/java/tomcat6/slf4j-log4j12-1.6.6.jar
java    14503 tomcat  mem    REG              253,0    481535    10209 /usr/share/java/tomcat6/log4j-1.2.16.jar
java    14503 tomcat  mem    REG              253,0    378088  1065276 /usr/share/java/log4j-1.2.14.jar
java    14503 tomcat   20r   REG              253,0    378088  1065276 /usr/share/java/log4j-1.2.14.jar
java    14503 tomcat   21r   REG              253,0    481535    10209 /usr/share/java/tomcat6/log4j-1.2.16.jar
java    14503 tomcat   35r   REG              253,0      9711    10208 /usr/share/java/tomcat6/slf4j-log4j12-1.6.6.jar
# 

Solr使用以下log4j.properties文件(通过-Dlog4j.configuration = file:///opt/solr/lib/log4j.properties)

#  Logging level
log4j.rootLogger=INFO, file, CONSOLE, SYSLOG

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=%-4r [%t] %-5p %c %x \u2013 %m%n

#- size rotation with log cleanup.
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.MaxFileSize=4MB
log4j.appender.file.MaxBackupIndex=9

#- File to log to and log format
log4j.appender.file.File=/var/log/tomcat6/solr.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%-5p - %d{yyyy-MM-dd HH:mm:ss.SSS}; %C; %m\n

log4j.logger.org.apache.zookeeper=WARN
log4j.logger.org.apache.hadoop=WARN

# set to INFO to enable infostream log messages
log4j.logger.org.apache.solr.update.LoggingInfoStream=OFF

#- Local syslog server
log4j.appender.SYSLOG=org.apache.log4j.net.SyslogAppender
log4j.appender.SYSLOG.syslogHost=localhost
log4j.appender.SYSLOG.facility=LOCAL1
log4j.appender.SYSLOG.layout=org.apache.log4j.PatternLayout
log4j.appender.SYSLOG.layout.ConversionPattern=${sysloghostname} %-4r [%t] java %-5p %c %x %m%n
log4j.appender.SYSLOG.Header=true

在同一台服务器上,我运行rsyslog并接受来自log4j的日志消息.

# rpmquery -a | grep syslog
rsyslog-5.8.10-7.el6_4.x86_64
# 

rsyslog配置

# #### MODULES ####
$MaxMessageSize 32k
$ModLoad imuxsock # provides support for local system logging (e.g. via logger command)
$ModLoad imklog   # provides kernel logging support (previously done by rklogd)
$ModLoad imfile   # provides file monitoring support
#
$ModLoad imudp.so
$UDPServerRun 514
$WorkDirectory /var/lib/rsyslog # where to place spool files
# #### GLOBAL DIRECTIVES ####
# # Use default timestamp format
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$IncludeConfig /etc/rsyslog.d/*.conf
$ActionQueueType LinkedList   # run asynchronously
$ActionQueueFileName fwdRule1 # unique name prefix for spool files
$ActionQueueMaxDiskSpace 1g   # 1gb space limit (use as much as possible)
$ActionQueueSaveOnShutdown on # save messages to disk on shutdown
$ActionResumeRetryCount -1    # infinite retries if host is down

$ActionSendStreamDriverMode 0 # require TLS for the connection
$ActionSendStreamDriverAuthMode anon # chain and server are verified
#local1.*;*.* @@(o)XXXXXXXX:5544
local1.*                                                /var/log/remote.log
# # The authpriv file has restricted access.
authpriv.*                                              /var/log/secure
# # Log all the mail messages in one place.
mail.*                                                  -/var/log/maillog
# # Log cron stuff
cron.*                                                  /var/log/cron
# # Everybody gets emergency messages
*.emerg                                                 *
# # Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler
# # Save boot messages also to boot.log
local7.*                                                /var/log/boot.log

我从Solr的logj4捕获local1消息并将它们重定向到/var/log/remote.log一切都按预期工作.示例INFO消息

Oct 31 13:57:08 hostname.here 3431839 [http-8080-10] java INFO  org.apache.solr.core.SolrCore  [collection1] webapp=/solr path=/select params={indent=true&q=*:*&wt=json&rows=1} hits=42917 status=0 QTime=1

堆栈跟踪与ERROR消息在同一行

Oct 31 12:27:17 hostname.here 157666248 [http-8080-7] java ERROR org.apache.solr.core.SolrCore  org.apache.solr.common.SolrException: undefined field *#012#011at org.apache.solr.schema.IndexSchema.getDynamicFieldType(IndexSchema.java:1223)#012... Cut for brevity....#011at java.lang.Thread.run(Thread.java:724)#012

注意#012为行尾和#011选项卡.

使用此设置,我可以通过TCP将日志发送到远程rsyslog服务器并将它们传输到fluentd/elaticsearch/kibana等......一切都按预期工作.

问题 我现在试图让另一个webapp在同一个tomcat容器内运行,如上所述,一切都按预期工作,除了堆栈跟踪,堆栈跟踪的每一行最终都在一个单独的行上(单独的syslog消息)

Oct 31 12:54:47  hostname.here 4909 [main] java ERROR org.hibernate.tool.hbm2ddl.SchemaUpdate  could not get database metadata
Oct 31 12:54:47 hostname.here org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (Communications link failure
Oct 31 12:54:47 hostname.here 
Oct 31 12:54:47 hostname.here The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.)

webapp附带了自己的log4j libs和log4j.xml配置.Libs与solr使用的版本相同.

此应用程序的log4j.xml文件

 <appender name="SYSLOG" class="org.apache.log4j.net.SyslogAppender">
                <param name="SyslogHost" value="localhost" />
                <param name="Facility" value="LOCAL1" />
                <param name="Header" value="false" />
                <property name="facilityPrinting" value="false"/>
                <param name="Threshold" value="DEBUG" />
                <layout class="org.apache.log4j.PatternLayout">
                <param name="ConversionPattern"
                      value="%-4r [%t] java %-5p %c %x %m%n"/>
                </layout>
                </appender>

我希望看到新应用程序中的堆栈跟踪与Solr一样出现在同一行.

有谁知道这是否是log4j配置问题？

非常感谢.

Answer 1

我最近一直在研究类似的事情（事实上，我目前正在解决这个问题，您可能可以提供帮助）。

这可能不是一个很好的答案，但它的信息量超出了我在评论中所能容纳的信息，所以就在这里（我希望其中一些对您来说是新的）。rsyslog imfile rsyslog 文档有此部分：

读取模式[模式]

当有多行消息时应定义此模式。该值的范围为 0-2，决定多线检测方法。
0（默认）- 基于行（每行都是一条新消息）
1 - 段落（日志消息之间有一个空行）
2 - 缩进（新日志消息从行的开头开始。如果行以空格开头它是之前日志消息的一部分）

imudp rsyslog文档没有这样的配置选项。我的猜测是 UDP 输入模块不支持多行日志记录。因此，堆栈跟踪的每一行都作为单独的日志条目发送出去。

/etc/rsyslog.d 中有配置文件吗？里面可能还有更多的信息。