You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@logging.apache.org by "Ralph Goers (JIRA)" <ji...@apache.org> on 2017/07/29 06:37:02 UTC
[jira] [Updated] (LOG4J2-1311) SocketAppender will lose several
events after re-connection to server
[ https://issues.apache.org/jira/browse/LOG4J2-1311?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ralph Goers updated LOG4J2-1311:
--------------------------------
Summary: SocketAppender will lose several events after re-connection to server (was: SocketAppender will loose several events after re-connection to server)
> SocketAppender will lose several events after re-connection to server
> ---------------------------------------------------------------------
>
> Key: LOG4J2-1311
> URL: https://issues.apache.org/jira/browse/LOG4J2-1311
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.5
> Environment: OS: Ubuntu 14.04 LTS
> Reporter: Xibing Liang
>
> -------> Firstly, I'd like to describe some conditions of our environment:
> 1) Our application use SocketAppender(TCP) for audit logs and SocketAppender(UDP) for system logs and the problem occur for TCP case.
> 2) We have two logstash servers and there is one HAProxy Server(172.16.64.236) for load balance usage between one application server(10.111.131.28) and two logstash servers(172.16.64.33 and 172.16.64.3).
> 3) Haproxy Server will break the connection if the connection is idle for several minutes, e.g. 10 minutes as we set.
> 4) The content of log4j2.properties(You can only focus on the TCP SocketAppender part):
> {code}
> status=TRACE
> name=TestOneLogConfig
>
> property.filename=/var/log/test-one-log/test-one-log.log
>
> #filters=threshold
>
> #filter.threshold.type=ThresholdFilter
> #filter.threshold.level=debug
>
> appenders=console, rolling, syslog, auditlog
>
> appender.console.type=Console
> appender.console.name=STDOUT
> appender.console.layout.type=PatternLayout
> appender.console.layout.pattern=%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n
>
> appender.rolling.type=RollingFile
> appender.rolling.name=RollingFile
> appender.rolling.fileName=${filename}
> appender.rolling.filePattern=/var/log/test-one-log/test-one-log-%d{MM-dd-yy-HH-mm-ss}-%i.log.gz
> appender.rolling.layout.type=PatternLayout
> appender.rolling.layout.pattern=%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n
> appender.rolling.policies.type=Policies
> appender.rolling.policies.time.type=TimeBasedTriggeringPolicy
> appender.rolling.policies.time.interval=2
> appender.rolling.policies.time.modulate=true
> appender.rolling.policies.size.type=SizeBasedTriggeringPolicy
> appender.rolling.policies.size.size=100MB
> appender.rolling.strategy.type=DefaultRolloverStrategy
> appender.rolling.strategy.max=5
> appender.syslog.type=Socket
> appender.syslog.name=UDPSocket
> appender.syslog.layout.type=JsonLayout
> appender.syslog.layout.locationInfo=true
> appender.syslog.layout.properties=true
> appender.syslog.protocol=UDP
> appender.syslog.host=172.16.64.3
> appender.syslog.port=4562
> appender.auditlog.type=Socket
> appender.auditlog.name=TCPSocket
> appender.auditlog.layout.type=JsonLayout
> appender.auditlog.layout.locationInfo=true
> appender.auditlog.layout.properties=true
> appender.auditlog.protocol=TCP
> appender.auditlog.host=172.16.64.236
> appender.auditlog.port=4561
> appender.auditlog.connectTimeoutMillis=3000
> appender.auditlog.reconnectionDelayMillis=3000
> appender.auditlog.immediateFail=true
> appender.auditlog.immediateFlush=false
> appender.auditlog.ignoreExceptions=false
> #appender.asyncauditlog.type=Async
> #appender.asyncauditlog.name=AsyncTCPSocket
> #appender.asyncauditlog.blocking=false
> #appender.asyncauditlog.bufferSize=2048
> #appender.asyncauditlog.ignoreExceptions=false
> #appender.asyncauditlog.asyncaudit.type=AppenderRef
> #appender.asyncauditlog.asyncaudit.ref=TCPSocket
> loggers=auditlogger
>
> logger.auditlogger.name=auditlogger
> logger.auditlogger.level=debug
> #logger.auditlogger.additivity=false
> logger.auditlogger.appenderRefs=auditlog
> logger.auditlogger.appenderRef.auditlog.ref=TCPSocket
>
> rootLogger.level=debug
> rootLogger.appenderRefs=console, rolling, syslog
> rootLogger.appenderRef.console.ref=STDOUT
> rootLogger.appenderRef.rolling.ref=RollingFile
> rootLogger.appenderRef.syslog.ref=UDPSocket
> {code}
> -------> Secondly, the process/steps of meeting problem:
> 1) Logstash servers, HAProxy servers and our application servers are up, and the application servers send audit logs to haproxy and logstash successfully.
> 2) As we didn't do any operation, there is no audit logs come into haproxy in several minutes, and haproxy break the connection between it and application server. I use "netstat -antp" to check tcp connection states and found that: from the harpoxy server's pov, there is no connection to its 4561 tcp port and from the application server's pov, the connection to haproxy's 4561 port is CLOSE_WAIT
> 3) We did a operation so that application server will write one audit log. However nothing happen, SocketAppender didn't throw any exception. And I can see that previous CLOSE_WAIT connection is also gone. This audit log didn't come into haproxy and logstash at all.
> 4) We did a second operation so that application server will write the second audit log. However now SocketAppender throw a exception of and our application catches it and write the system log about it. This audit log didn't come into haproxy and logstash either.
> 5) We did a third operation so that application server will write the third audit log. This time SocketAppender works well and this audit log came into haproxy and logstash.
> -------> So our question is that:
> 1) What's the reason of this situation, do you have any idea?
> 2) Is there any solution to write the first and second audit log to log server finally? The audit log is really importance for us.
> P.S.
> Here I paste the logs of console(from eclipse), you can see there are serveral prints of "DEBUG auditlogger:57 - LXB 0.0.0.0 xClone roles successfully" after re-connection, however logstash only receive the last one:
> {code}
> 三月 09, 2016 4:58:01 下午 org.apache.catalina.core.AprLifecycleListener init
> 信息: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 三月 09, 2016 4:58:01 下午 org.apache.tomcat.util.digester.SetPropertiesRule begin
> 警告: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.j2ee.server:test-one-log' did not find a matching property.
> 三月 09, 2016 4:58:02 下午 org.apache.coyote.AbstractProtocol init
> 信息: Initializing ProtocolHandler ["http-bio-8080"]
> 三月 09, 2016 4:58:02 下午 org.apache.coyote.AbstractProtocol init
> 信息: Initializing ProtocolHandler ["ajp-bio-8009"]
> 三月 09, 2016 4:58:02 下午 org.apache.catalina.startup.Catalina load
> 信息: Initialization processed in 1050 ms
> 三月 09, 2016 4:58:02 下午 org.apache.catalina.core.StandardService startInternal
> 信息: Starting service Catalina
> 三月 09, 2016 4:58:02 下午 org.apache.catalina.core.StandardEngine startInternal
> 信息: Starting Servlet Engine: Apache Tomcat/7.0.47
> 三月 09, 2016 4:58:03 下午 org.apache.catalina.loader.WebappClassLoader validateJarFile
> 信息: validateJarFile(/home/xibing-liang/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp2/wtpwebapps/test-one-log/WEB-INF/lib/javax.servlet-api-3.1.0.jar) - jar not loaded. See Servlet Spec 2.3, section 9.7.2. Offending class: javax/servlet/Servlet.class
> 三月 09, 2016 4:58:06 下午 org.apache.catalina.core.ApplicationContext log
> 信息: No Spring WebApplicationInitializer types detected on classpath
> SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
> SLF4J: Defaulting to no-operation (NOP) logger implementation
> SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
> 三月 09, 2016 4:58:06 下午 org.apache.catalina.core.ApplicationContext log
> 信息: Initializing Spring root WebApplicationContext
> 三月 09, 2016 4:58:07 下午 org.apache.catalina.core.ApplicationContext log
> 信息: Initializing Spring FrameworkServlet 'mvc-dispatcher'
> 2016-03-09 16:58:07,694 localhost-startStop-1 DEBUG Initializing configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@574c1328
> 2016-03-09 16:58:07,705 localhost-startStop-1 DEBUG Installed script engines
> 2016-03-09 16:58:07,717 localhost-startStop-1 DEBUG Mozilla Rhino Version: 1.7 release 3 PRERELEASE, Language: ECMAScript, Threading: MULTITHREADED, Compile: true, Names: {js, rhino, JavaScript, javascript, ECMAScript, ecmascript}
> 2016-03-09 16:58:07,718 localhost-startStop-1 DEBUG PluginManager 'Core' found 97 plugins
> 2016-03-09 16:58:07,718 localhost-startStop-1 DEBUG PluginManager 'Level' found 0 plugins
> 2016-03-09 16:58:07,723 localhost-startStop-1 DEBUG No scheduled items
> 2016-03-09 16:58:07,724 localhost-startStop-1 DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
> 2016-03-09 16:58:07,740 localhost-startStop-1 TRACE TypeConverterRegistry initializing.
> 2016-03-09 16:58:07,740 localhost-startStop-1 DEBUG PluginManager 'TypeConverter' found 23 plugins
> 2016-03-09 16:58:07,749 localhost-startStop-1 DEBUG createProperty(name="filename", value="/var/log/test-one-log/test-one-log.log")
> 2016-03-09 16:58:07,750 localhost-startStop-1 DEBUG Building Plugin[name=properties, class=org.apache.logging.log4j.core.config.PropertiesPlugin].
> 2016-03-09 16:58:07,770 localhost-startStop-1 DEBUG configureSubstitutor(={filename=/var/log/test-one-log/test-one-log.log}, Configuration(TestOneLogConfig))
> 2016-03-09 16:58:07,771 localhost-startStop-1 DEBUG PluginManager 'Lookup' found 13 plugins
> 2016-03-09 16:58:07,771 localhost-startStop-1 DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-03-09 16:58:07,772 localhost-startStop-1 DEBUG createAppenderRef(ref="TCPSocket", level="null", Filter=null)
> 2016-03-09 16:58:07,773 localhost-startStop-1 DEBUG Building Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
> 2016-03-09 16:58:07,776 localhost-startStop-1 DEBUG createLogger(additivity="null", level="DEBUG", name="auditlogger", includeLocation="null", ={TCPSocket}, ={}, Configuration(TestOneLogConfig), Filter=null)
> 2016-03-09 16:58:07,779 localhost-startStop-1 DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-03-09 16:58:07,780 localhost-startStop-1 DEBUG createAppenderRef(ref="STDOUT", level="null", Filter=null)
> 2016-03-09 16:58:07,780 localhost-startStop-1 DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-03-09 16:58:07,783 localhost-startStop-1 DEBUG createAppenderRef(ref="RollingFile", level="null", Filter=null)
> 2016-03-09 16:58:07,783 localhost-startStop-1 DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-03-09 16:58:07,784 localhost-startStop-1 DEBUG createAppenderRef(ref="UDPSocket", level="null", Filter=null)
> 2016-03-09 16:58:07,784 localhost-startStop-1 DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
> 2016-03-09 16:58:07,786 localhost-startStop-1 DEBUG createLogger(additivity="null", level="DEBUG", includeLocation="null", ={STDOUT, RollingFile, UDPSocket}, ={}, Configuration(TestOneLogConfig), Filter=null)
> 2016-03-09 16:58:07,787 localhost-startStop-1 DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
> 2016-03-09 16:58:07,788 localhost-startStop-1 DEBUG createLoggers(={auditlogger, root})
> 2016-03-09 16:58:07,788 localhost-startStop-1 DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-03-09 16:58:07,821 localhost-startStop-1 DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n", PatternSelector=null, Configuration(TestOneLogConfig), Replace=null, charset="null", alwaysWriteExceptions="null", noConsoleNoAnsi="null", header="null", footer="null")
> 2016-03-09 16:58:07,822 localhost-startStop-1 DEBUG PluginManager 'Converter' found 38 plugins
> 2016-03-09 16:58:07,887 localhost-startStop-1 DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
> 2016-03-09 16:58:07,895 localhost-startStop-1 INFO Log4j appears to be running in a Servlet environment, but there's no log4j-web module available. If you want better web container support, please add the log4j-web JAR to your web archive or server lib directory.
> 2016-03-09 16:58:07,896 localhost-startStop-1 DEBUG PluginManager 'Converter' found 38 plugins
> 2016-03-09 16:58:07,899 localhost-startStop-1 DEBUG Starting OutputStreamManager SYSTEM_OUT.false-2
> 2016-03-09 16:58:07,930 localhost-startStop-1 DEBUG ConsoleAppender$Builder(PatternLayout(%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n), Filter=null, target="null", name="STDOUT", follow="null", ignoreExceptions="null")
> 2016-03-09 16:58:07,938 localhost-startStop-1 DEBUG Starting OutputStreamManager SYSTEM_OUT.false
> 2016-03-09 16:58:07,940 localhost-startStop-1 DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-03-09 16:58:07,942 localhost-startStop-1 DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n", PatternSelector=null, Configuration(TestOneLogConfig), Replace=null, charset="null", alwaysWriteExceptions="null", noConsoleNoAnsi="null", header="null", footer="null")
> 2016-03-09 16:58:07,943 localhost-startStop-1 DEBUG Building Plugin[name=TimeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.TimeBasedTriggeringPolicy].
> 2016-03-09 16:58:07,946 localhost-startStop-1 DEBUG createPolicy(interval="2", modulate="true")
> 2016-03-09 16:58:07,947 localhost-startStop-1 DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
> 2016-03-09 16:58:07,951 localhost-startStop-1 DEBUG createPolicy(size="100MB")
> 2016-03-09 16:58:07,955 localhost-startStop-1 DEBUG Building Plugin[name=Policies, class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
> 2016-03-09 16:58:07,963 localhost-startStop-1 DEBUG createPolicy(={TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=2, modulate=true), SizeBasedTriggeringPolicy(size=104857600)})
> 2016-03-09 16:58:07,968 localhost-startStop-1 DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy].
> 2016-03-09 16:58:07,973 localhost-startStop-1 DEBUG createStrategy(max="5", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="true", Configuration(TestOneLogConfig))
> 2016-03-09 16:58:07,975 localhost-startStop-1 DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender].
> 2016-03-09 16:58:07,980 localhost-startStop-1 DEBUG createAppender(fileName="/var/log/test-one-log/test-one-log.log", filePattern="/var/log/test-one-log/test-one-log-%d{MM-dd-yy-HH-mm-ss}-%i.log.gz", append="null", name="RollingFile", bufferedIO="null", bufferSize="null", immediateFlush="null", Policies(CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=2, modulate=true), SizeBasedTriggeringPolicy(size=104857600)])), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=5)), PatternLayout(%d{yyyy-MM-dd HH:mm:ss} [%t] %p %c:%L - %m%n), Filter=null, ignoreExceptions="null", advertise="null", advertiseURI="null", Configuration(TestOneLogConfig))
> 2016-03-09 16:58:07,990 localhost-startStop-1 DEBUG Starting RollingFileManager /var/log/test-one-log/test-one-log.log
> 2016-03-09 16:58:07,994 localhost-startStop-1 DEBUG PluginManager 'FileConverter' found 2 plugins
> 2016-03-09 16:58:07,997 localhost-startStop-1 TRACE PatternProcessor.getNextTime returning 2016/03/09-16:45:52.000, nextFileTime=2016/03/09-16:45:51.000, prevFileTime=1970/01/01-08:00:00.000, current=2016/03/09-16:58:07.997, freq=EVERY_SECOND
> 2016-03-09 16:58:08,003 localhost-startStop-1 TRACE PatternProcessor.getNextTime returning 2016/03/09-16:45:52.000, nextFileTime=2016/03/09-16:45:51.000, prevFileTime=2016/03/09-16:45:51.000, current=2016/03/09-16:58:08.002, freq=EVERY_SECOND
> 2016-03-09 16:58:08,003 localhost-startStop-1 DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.JsonLayout].
> 2016-03-09 16:58:08,012 localhost-startStop-1 DEBUG createLayout(locationInfo="true", properties="true", complete="false", compact="false", eventEol="false", charset="UTF-8")
> 2016-03-09 16:58:08,301 localhost-startStop-1 DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.SocketAppender].
> 2016-03-09 16:58:08,308 localhost-startStop-1 DEBUG createAppender(host="172.16.64.3", port="4562", protocol="UDP", SSL=null, connectTimeoutMillis="0", reconnectionDelayMillis="0", immediateFail="true", name="UDPSocket", immediateFlush="true", ignoreExceptions="true", JsonLayout(org.apache.logging.log4j.core.layout.JsonLayout@35e97fc3), Filter=null, advertise="false", Configuration(TestOneLogConfig))
> 2016-03-09 16:58:08,311 localhost-startStop-1 DEBUG Starting DatagramSocketManager UDP:172.16.64.3:4562
> 2016-03-09 16:58:08,312 localhost-startStop-1 DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.JsonLayout].
> 2016-03-09 16:58:08,313 localhost-startStop-1 DEBUG createLayout(locationInfo="true", properties="true", complete="false", compact="false", eventEol="false", charset="UTF-8")
> 2016-03-09 16:58:08,313 localhost-startStop-1 DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.SocketAppender].
> 2016-03-09 16:58:08,316 localhost-startStop-1 DEBUG createAppender(host="172.16.64.236", port="4561", protocol="TCP", SSL=null, connectTimeoutMillis="3000", reconnectionDelayMillis="3000", immediateFail="true", name="TCPSocket", immediateFlush="false", ignoreExceptions="false", JsonLayout(org.apache.logging.log4j.core.layout.JsonLayout@6ab715ca), Filter=null, advertise="false", Configuration(TestOneLogConfig))
> 2016-03-09 16:58:08,322 localhost-startStop-1 DEBUG Starting TcpSocketManager TCP:172.16.64.236:4561
> 2016-03-09 16:58:08,323 localhost-startStop-1 DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
> 2016-03-09 16:58:08,323 localhost-startStop-1 DEBUG createAppenders(={STDOUT, RollingFile, UDPSocket, TCPSocket})
> 2016-03-09 16:58:08,324 localhost-startStop-1 DEBUG Configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@574c1328 initialized
> 2016-03-09 16:58:08,325 localhost-startStop-1 DEBUG Starting configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@574c1328
> 2016-03-09 16:58:08,326 localhost-startStop-1 DEBUG Started configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@574c1328 OK.
> 2016-03-09 16:58:08,326 localhost-startStop-1 TRACE Stopping org.apache.logging.log4j.core.config.DefaultConfiguration@5332203...
> 2016-03-09 16:58:08,327 localhost-startStop-1 TRACE DefaultConfiguration notified 1 ReliabilityStrategies that config will be stopped.
> 2016-03-09 16:58:08,327 localhost-startStop-1 TRACE DefaultConfiguration stopping root LoggerConfig.
> 2016-03-09 16:58:08,327 localhost-startStop-1 TRACE DefaultConfiguration notifying ReliabilityStrategies that appenders will be stopped.
> 2016-03-09 16:58:08,327 localhost-startStop-1 TRACE DefaultConfiguration stopping remaining Appenders.
> 2016-03-09 16:58:08,328 localhost-startStop-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false-1
> 2016-03-09 16:58:08,328 localhost-startStop-1 TRACE DefaultConfiguration stopped 1 remaining Appenders.
> 2016-03-09 16:58:08,328 localhost-startStop-1 TRACE DefaultConfiguration cleaning Appenders from 1 LoggerConfigs.
> 2016-03-09 16:58:08,329 localhost-startStop-1 DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@5332203 OK
> 2016-03-09 16:58:08,339 localhost-startStop-1 TRACE Reregistering MBeans after reconfigure. Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@769c48b
> 2016-03-09 16:58:08,339 localhost-startStop-1 TRACE Reregistering context (1/1): '602fc7b3' org.apache.logging.log4j.core.LoggerContext@30e6857a
> 2016-03-09 16:58:08,340 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3'
> 2016-03-09 16:58:08,340 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=StatusLogger'
> 2016-03-09 16:58:08,341 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=ContextSelector'
> 2016-03-09 16:58:08,341 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=Loggers,name=*'
> 2016-03-09 16:58:08,342 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=Appenders,name=*'
> 2016-03-09 16:58:08,342 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=AsyncAppenders,name=*'
> 2016-03-09 16:58:08,342 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=AsyncLoggerRingBuffer'
> 2016-03-09 16:58:08,343 localhost-startStop-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=602fc7b3,component=Loggers,name=*,subtype=RingBuffer'
> 2016-03-09 16:58:08,344 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3
> 2016-03-09 16:58:08,350 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=StatusLogger
> 2016-03-09 16:58:08,352 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=ContextSelector
> 2016-03-09 16:58:08,354 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Loggers,name=
> 2016-03-09 16:58:08,355 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Loggers,name=auditlogger
> 2016-03-09 16:58:08,356 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Appenders,name=UDPSocket
> 2016-03-09 16:58:08,357 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Appenders,name=RollingFile
> 2016-03-09 16:58:08,357 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Appenders,name=STDOUT
> 2016-03-09 16:58:08,357 localhost-startStop-1 DEBUG Registering MBean org.apache.logging.log4j2:type=602fc7b3,component=Appenders,name=TCPSocket
> 2016-03-09 16:58:08,359 localhost-startStop-1 TRACE Using default SystemClock for timestamps.
> 2016-03-09 16:58:08,360 localhost-startStop-1 TRACE Using DummyNanoClock for nanosecond timestamps.
> 2016-03-09 16:58:08,370 localhost-startStop-1 DEBUG Reconfiguration complete for context[name=602fc7b3] at URI NULL_SOURCE (org.apache.logging.log4j.core.LoggerContext@30e6857a) with optional ClassLoader: null
> 2016-03-09 16:58:08,370 localhost-startStop-1 DEBUG Shutdown hook enabled. Registering a new one.
> 2016-03-09 16:58:08,371 localhost-startStop-1 DEBUG LoggerContext[name=602fc7b3, org.apache.logging.log4j.core.LoggerContext@30e6857a] started OK.
> 三月 09, 2016 4:58:08 下午 org.hibernate.validator.internal.util.Version <clinit>
> INFO: HV000001: Hibernate Validator 5.1.3.Final
> 三月 09, 2016 4:58:09 下午 org.apache.coyote.AbstractProtocol start
> 信息: Starting ProtocolHandler ["http-bio-8080"]
> 三月 09, 2016 4:58:09 下午 org.apache.coyote.AbstractProtocol start
> 信息: Starting ProtocolHandler ["ajp-bio-8009"]
> 三月 09, 2016 4:58:09 下午 org.apache.catalina.startup.Catalina start
> 信息: Server startup in 7725 ms
> 2016-03-09 17:00:33 [http-bio-8080-exec-5] DEBUG www.chinacloud.com.api.ProxyController:55 - roles xClone
> 2016-03-09 17:00:33,022 http-bio-8080-exec-5 TRACE PatternProcessor.getNextTime returning 2016/03/09-17:00:34.000, nextFileTime=2016/03/09-17:00:33.000, prevFileTime=2016/03/09-16:45:51.000, current=2016/03/09-17:00:33.022, freq=EVERY_SECOND
> 2016-03-09 17:00:33,026 http-bio-8080-exec-5 TRACE DefaultRolloverStrategy.purge() took 3.0 milliseconds
> 2016-03-09 17:00:33,029 http-bio-8080-exec-5 DEBUG RollingFileManager executing synchronous FileRenameAction[/var/log/test-one-log/test-one-log.log to /var/log/test-one-log/test-one-log-03-09-16-16-45-51-1.log, renameEmptyFiles=false]
> 2016-03-09 17:00:33,029 http-bio-8080-exec-5 DEBUG RollingFileManager executing async GzCompressAction[/var/log/test-one-log/test-one-log-03-09-16-16-45-51-1.log to /var/log/test-one-log/test-one-log-03-09-16-16-45-51-1.log.gz, deleteSource=true]
> 2016-03-09 17:00:33 [http-bio-8080-exec-5] DEBUG auditlogger:57 - LXB 0.0.0.0 xClone roles successfully
> PHPSESSID=kuk0kaclb0ogi2b9huei4hel02; expires=Wed, 09-Mar-2016 09:30:39 GMT; Max-Age=1800; path=/; HttpOnly
> 2016-03-09 17:14:03 [http-bio-8080-exec-7] DEBUG www.chinacloud.com.api.ProxyController:55 - roles xClone
> 2016-03-09 17:14:03,015 http-bio-8080-exec-7 TRACE PatternProcessor.getNextTime returning 2016/03/09-17:14:04.000, nextFileTime=2016/03/09-17:14:03.000, prevFileTime=2016/03/09-17:00:33.000, current=2016/03/09-17:14:03.013, freq=EVERY_SECOND
> 2016-03-09 17:14:03,017 http-bio-8080-exec-7 TRACE DefaultRolloverStrategy.purge() took 1.0 milliseconds
> 2016-03-09 17:14:03,017 http-bio-8080-exec-7 DEBUG RollingFileManager executing synchronous FileRenameAction[/var/log/test-one-log/test-one-log.log to /var/log/test-one-log/test-one-log-03-09-16-17-00-33-1.log, renameEmptyFiles=false]
> 2016-03-09 17:14:03,018 http-bio-8080-exec-7 DEBUG RollingFileManager executing async GzCompressAction[/var/log/test-one-log/test-one-log-03-09-16-17-00-33-1.log to /var/log/test-one-log/test-one-log-03-09-16-17-00-33-1.log.gz, deleteSource=true]
> 2016-03-09 17:14:03 [http-bio-8080-exec-7] DEBUG auditlogger:57 - LXB 0.0.0.0 xClone roles successfully
> PHPSESSID=kuk0kaclb0ogi2b9huei4hel02; expires=Wed, 09-Mar-2016 09:44:08 GMT; Max-Age=1800; path=/; HttpOnly
> 2016-03-09 17:14:45 [http-bio-8080-exec-9] DEBUG www.chinacloud.com.api.ProxyController:55 - roles xClone
> 2016-03-09 17:14:45,034 http-bio-8080-exec-9 TRACE PatternProcessor.getNextTime returning 2016/03/09-17:14:46.000, nextFileTime=2016/03/09-17:14:45.000, prevFileTime=2016/03/09-17:14:03.000, current=2016/03/09-17:14:45.034, freq=EVERY_SECOND
> 2016-03-09 17:14:45,035 http-bio-8080-exec-9 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
> 2016-03-09 17:14:45,035 http-bio-8080-exec-9 DEBUG RollingFileManager executing synchronous FileRenameAction[/var/log/test-one-log/test-one-log.log to /var/log/test-one-log/test-one-log-03-09-16-17-14-03-1.log, renameEmptyFiles=false]
> 2016-03-09 17:14:45,035 http-bio-8080-exec-9 DEBUG RollingFileManager executing async GzCompressAction[/var/log/test-one-log/test-one-log-03-09-16-17-14-03-1.log to /var/log/test-one-log/test-one-log-03-09-16-17-14-03-1.log.gz, deleteSource=true]
> 2016-03-09 17:14:45,048 http-bio-8080-exec-9 ERROR Unable to write to stream TCP:172.16.64.236:4561 for appender TCPSocket
> 2016-03-09 17:14:45,048 http-bio-8080-exec-9 ERROR An exception occurred processing Appender TCPSocket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing to TCP:172.16.64.236:4561
> at org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:140)
> at org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:136)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:114)
> at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:152)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:125)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:116)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:390)
> at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:378)
> at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:362)
> at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:352)
> at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:147)
> at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1022)
> at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:980)
> at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:239)
> at www.chinacloud.com.api.ProxyController.post(ProxyController.java:57)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221)
> at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137)
> at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110)
> at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776)
> at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705)
> at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
> at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959)
> at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893)
> at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966)
> at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
> at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
> at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
> at www.chinacloud.com.filter.CORSFilter.doFilter(CORSFilter.java:28)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
> at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
> at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1041)
> at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603)
> at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.net.SocketException: 断开的管道
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
> at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
> at org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:131)
> ... 55 more
> 2016-03-09 17:14:45 [http-bio-8080-exec-9] ERROR www.chinacloud.com.api.ProxyController:61 - LXB Audit Error: Error writing to TCP:172.16.64.236:4561
> PHPSESSID=kuk0kaclb0ogi2b9huei4hel02; expires=Wed, 09-Mar-2016 09:44:51 GMT; Max-Age=1800; path=/; HttpOnly
> 2016-03-09 17:14:48,095 Thread-3 DEBUG Connection to 172.16.64.236:4561 reestablished.
> 2016-03-09 17:15:39 [http-bio-8080-exec-1] DEBUG www.chinacloud.com.api.ProxyController:55 - roles xClone
> 2016-03-09 17:15:39,434 http-bio-8080-exec-1 TRACE PatternProcessor.getNextTime returning 2016/03/09-17:15:40.000, nextFileTime=2016/03/09-17:15:39.000, prevFileTime=2016/03/09-17:14:45.000, current=2016/03/09-17:15:39.434, freq=EVERY_SECOND
> 2016-03-09 17:15:39,435 http-bio-8080-exec-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
> 2016-03-09 17:15:39,436 http-bio-8080-exec-1 DEBUG RollingFileManager executing synchronous FileRenameAction[/var/log/test-one-log/test-one-log.log to /var/log/test-one-log/test-one-log-03-09-16-17-14-45-1.log, renameEmptyFiles=false]
> 2016-03-09 17:15:39,436 http-bio-8080-exec-1 DEBUG RollingFileManager executing async GzCompressAction[/var/log/test-one-log/test-one-log-03-09-16-17-14-45-1.log to /var/log/test-one-log/test-one-log-03-09-16-17-14-45-1.log.gz, deleteSource=true]
> 2016-03-09 17:15:39 [http-bio-8080-exec-1] DEBUG auditlogger:57 - LXB 0.0.0.0 xClone roles successfully
> PHPSESSID=kuk0kaclb0ogi2b9huei4hel02; expires=Wed, 09-Mar-2016 09:45:45 GMT; Max-Age=1800; path=/; HttpOnly
> {code}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)