[
https://issues.apache.org/jira/browse/LOG4J2-1918?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ralph Goers updated LOG4J2-1918:
--------------------------------
Description:
We are facing intermittent lost of logs while sending logs to log target using
log4j2 socket appender in our application. The detailed information is as below;
Our environment:
1) In our application, we are using log4j2 (2.8.1 version jar) framework and
SocketAppender (async appender under socket appender) to send logs to Splunk (
Enterprise Logging tool) via radware(load balancer).
2) So our application connects to Radware over TCPIP socket using
SocketAppender; Radware is used to load balance load among 4 target Splunk
servers.
3) Radware Server is configured to timeout if connection is idle for one minute
(configurable at radware and set to 1 minute)
4) The configuration of log4j2 config file is as below
{code}
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="trace" monitorInterval="5">
<Appenders>
<Socket name="socket" host="10.52.214.26" port="1514"
reconnectDelayMillis="30000" immediateFail="false" bufferedIo="true"
bufferSize="204800" protocol="TCP" immediateFlush="false">
<PatternLayout></PatternLayout>
</Socket>
<Async name="SplunkAsync" bufferSize="204800">
<AppenderRef ref="socket"/>
</Async>
</Appenders>
<Loggers>
<Root level="warn">
<AppenderRef ref="SplunkAsync"/>
</Root>
<Logger name="SplunkInfoLogger" level="info" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
<Logger name="SplunkDebugLogger" level="debug" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
<Logger name="SplunkWarnLogger" level="warn" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
</Loggers>
</Configuration>
{code}
The process/steps of meeting problem:
1) Splunk servers, radware server and our application servers are up, and the
application servers send logs to radware in turn splunk servers successfully.
2) As we didn't do any operation, there is no logs come into radware in one
minute ( 1 minute as we set) and radware breaks the connection between it and
application server.
3) We did an operation so that application server will write one log. However
nothing happens, This log didn't come into radware and splunk servers at all.
4) We did a second operation so that application server will write the second
log. This time also logs did not come into radware and splunk either.
5) After counting for 30 sec (reconnectDelayMillis="30000" in log4j2 config
file) from first failed log ( i.e the log triggered after radware breaks
connection) we did a third operation so that application server will write the
third log. This time SocketAppender works well and this log came into radware
and splunk servers. This is primarily because application server is able to
re-establish connection to Radware after 30 sec as reconnectDelayMillis="30000"
I would like to know why initial logs are lost which are sent after radware
connection becomes idle. Ideally, tcp connection created by log4j2 should keep
the data in buffer when connection is broken and should send data from buffer
when reconnection is established after 30 secs (reconnectDelayMillis="30000" )
We tried setting up parameters like immediateFail="false" bufferedIo="true"
bufferSize="204800", so that data can be stored in buffer when radware times
out tcp connection and can be sent later when reconnection to radware is
established, Unfortunately which is not happening.
Are we missing any configurations because which we are facing this type of
behaviour or is it known defect.
The similar kind of issue is also observed by others and raised in apache
jira(https://issues.apache.org/jira/browse/LOG4J2-1311)
Context Log:
{code}
Listening for transport dt_socket at address: 6666
2017-05-15 17:27:05.706 1 Using jms interface URL:
file:/C:/Program%20Files/IBM/IIB/10.0.0.6/server/../common/classes/jms.jar
2017-05-15 17:27:05.724 1 Loaded JPLUG
2017-05-15 17:27:13.946 49 [15/5/17 17:27:13:397 IST] 00000031
ObjectGridRAS I CWOBJ2507I: Trace specification is set to *=off=enabled.
2017-05-15 17:27:14,671 Thread-39 DEBUG Initializing configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
2017-05-15 17:27:14.686 53 2017-05-15 17:27:14,686 Thread-39 DEBUG
Installed script engines
2017-05-15 17:27:14.754 53 2017-05-15 17:27:14,754 Thread-39 DEBUG Mozilla
Rhino Version: 1.7 release 3 PRERELEASE, Language: ECMAScript, Threading:
MULTITHREADED, Compile: true, Names: {js, rhino, JavaScript, javascript,
ECMAScript, ecmascript}
2017-05-15 17:27:14.756 53 2017-05-15 17:27:14,756 Thread-39 DEBUG
PluginManager 'Core' found 107 plugins
2017-05-15 17:27:14.757 53 2017-05-15 17:27:14,757 Thread-39 DEBUG
PluginManager 'Level' found 0 plugins
2017-05-15 17:27:14.765 53 2017-05-15 17:27:14,765 Thread-39 DEBUG 1
starting Log4j2 ConfigurationScheduler threads
2017-05-15 17:27:14.769 53 2017-05-15 17:27:14,768 Thread-39 DEBUG
PluginManager 'Lookup' found 13 plugins
2017-05-15 17:27:14.772 53 2017-05-15 17:27:14,772 Thread-39 DEBUG Building
Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2017-05-15 17:27:14.799 53 2017-05-15 17:27:14,798 Thread-39 TRACE
TypeConverterRegistry initializing.
2017-05-15 17:27:14.800 53 2017-05-15 17:27:14,800 Thread-39 DEBUG
PluginManager 'TypeConverter' found 23 plugins
2017-05-15 17:27:14.834 53 2017-05-15 17:27:14,834 Thread-39 DEBUG
PatternLayout$Builder(pattern="null", PatternSelector=null,
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Replace=null,
charset="null", alwaysWriteExceptions="null", noConsoleNoAnsi="null",
header="null", footer="null")
2017-05-15 17:27:14.836 53 2017-05-15 17:27:14,836 Thread-39 DEBUG
PluginManager 'Converter' found 41 plugins
2017-05-15 17:27:14.838 53 2017-05-15 17:27:14,838 Thread-39 DEBUG Building
Plugin[name=appender,
class=org.apache.logging.log4j.core.appender.SocketAppender].
2017-05-15 17:27:14.862 53 2017-05-15 17:27:14,862 Thread-39 DEBUG
SocketAppender$Builder(advertise="null",
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
connectTimeoutMillis="null", host="10.52.214.26", immediateFail="false",
port="1514", protocol="TCP", reconnectDelayMillis="30000",
SslConfiguration=null, bufferedIo="true", bufferSize="204800",
immediateFlush="false", ignoreExceptions="null", PatternLayout(%m%n),
name="socket", Filter=null)
2017-05-15 17:27:15.053 53 2017-05-15 17:27:15,052 Thread-39 DEBUG Starting
TcpSocketManager TCP:10.52.214.26:1514
2017-05-15 17:27:15.054 53 2017-05-15 17:27:15,054 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.066 53 2017-05-15 17:27:15,066 Thread-39 DEBUG
createAppenderRef(ref="socket", level="null", Filter=null)
2017-05-15 17:27:15.070 53 2017-05-15 17:27:15,070 Thread-39 DEBUG Building
Plugin[name=appender,
class=org.apache.logging.log4j.core.appender.AsyncAppender].
2017-05-15 17:27:15.081 53 2017-05-15 17:27:15,081 Thread-39 DEBUG
AsyncAppender$Builder(={socket}, errorRef="null", blocking="null",
shutdownTimeout="null", bufferSize="204800", name="SplunkAsync",
includeLocation="null", Filter=null,
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
ignoreExceptions="null", BlockingQueueFactory=null)
2017-05-15 17:27:15.084 53 2017-05-15 17:27:15,083 Thread-39 DEBUG Building
Plugin[name=appenders,
class=org.apache.logging.log4j.core.config.AppendersPlugin].
2017-05-15 17:27:15.086 53 2017-05-15 17:27:15,085 Thread-39 DEBUG
createAppenders(={socket, SplunkAsync})
2017-05-15 17:27:15.087 53 2017-05-15 17:27:15,087 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.089 53 2017-05-15 17:27:15,089 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.091 53 2017-05-15 17:27:15,090 Thread-39 DEBUG Building
Plugin[name=root,
class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2017-05-15 17:27:15.094 53 2017-05-15 17:27:15,094 Thread-39 DEBUG
createLogger(additivity="null", level="WARN", includeLocation="null",
={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.115 53 2017-05-15 17:27:15,113 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.120 53 2017-05-15 17:27:15,120 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.123 53 2017-05-15 17:27:15,123 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.128 53 2017-05-15 17:27:15,127 Thread-39 DEBUG
createLogger(additivity="false", level="INFO", name="SplunkInfoLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.130 53 2017-05-15 17:27:15,130 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.133 53 2017-05-15 17:27:15,132 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.134 53 2017-05-15 17:27:15,134 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.147 53 2017-05-15 17:27:15,146 Thread-39 DEBUG
createLogger(additivity="false", level="DEBUG", name="SplunkDebugLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.148 53 2017-05-15 17:27:15,148 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.151 53 2017-05-15 17:27:15,150 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.152 53 2017-05-15 17:27:15,152 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.156 53 2017-05-15 17:27:15,156 Thread-39 DEBUG
createLogger(additivity="false", level="WARN", name="SplunkWarnLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.158 53 2017-05-15 17:27:15,157 Thread-39 DEBUG Building
Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2017-05-15 17:27:15.165 53 2017-05-15 17:27:15,165 Thread-39 DEBUG
createLoggers(={root, SplunkInfoLogger, SplunkDebugLogger, SplunkWarnLogger})
2017-05-15 17:27:15.167 53 2017-05-15 17:27:15,167 Thread-39 DEBUG
Configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
initialized
2017-05-15 17:27:15.169 53 2017-05-15 17:27:15,168 Thread-39 DEBUG Starting
configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
2017-05-15 17:27:15.178 53 2017-05-15 17:27:15,178 Thread-39 DEBUG Started
configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml] OK.
2017-05-15 17:27:15.180 53 2017-05-15 17:27:15,180 Thread-39 TRACE Stopping
org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c...
2017-05-15 17:27:15.181 53 2017-05-15 17:27:15,181 Thread-39 TRACE
DefaultConfiguration notified 1 ReliabilityStrategies that config will be
stopped.
2017-05-15 17:27:15.184 53 2017-05-15 17:27:15,184 Thread-39 TRACE
DefaultConfiguration stopping root LoggerConfig.
2017-05-15 17:27:15.185 53 2017-05-15 17:27:15,185 Thread-39 TRACE
DefaultConfiguration notifying ReliabilityStrategies that appenders will be
stopped.
2017-05-15 17:27:15.187 53 2017-05-15 17:27:15,186 Thread-39 TRACE
DefaultConfiguration stopping remaining Appenders.
2017-05-15 17:27:15.188 53 2017-05-15 17:27:15,187 Thread-39 DEBUG Shutting
down OutputStreamManager SYSTEM_OUT.false.false-1
2017-05-15 17:27:15.189 53 2017-05-15 17:27:15,189 Thread-39 DEBUG Shut
down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2017-05-15 17:27:15.190 53 2017-05-15 17:27:15,190 Thread-39 TRACE
DefaultConfiguration stopped 1 remaining Appenders.
2017-05-15 17:27:15.191 53 2017-05-15 17:27:15,191 Thread-39 TRACE
DefaultConfiguration cleaning Appenders from 1 LoggerConfigs.
2017-05-15 17:27:15.193 53 2017-05-15 17:27:15,193 Thread-39 DEBUG Stopped
org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c OK
2017-05-15 17:27:15.198 53 2017-05-15 17:27:15,197 Thread-39 TRACE
Reregistering MBeans after reconfigure.
Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@7a7e9cb6
2017-05-15 17:27:15.199 53 2017-05-15 17:27:15,199 Thread-39 TRACE
Reregistering context (1/1): 'c1edad85'
org.apache.logging.log4j.core.LoggerContext@c1b7efc0
2017-05-15 17:27:15.200 53 2017-05-15 17:27:15,200 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85'
2017-05-15 17:27:15.202 53 2017-05-15 17:27:15,202 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=StatusLogger'
2017-05-15 17:27:15.203 53 2017-05-15 17:27:15,203 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=ContextSelector'
2017-05-15 17:27:15.205 53 2017-05-15 17:27:15,205 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*'
2017-05-15 17:27:15.213 53 2017-05-15 17:27:15,213 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=*'
2017-05-15 17:27:15.215 53 2017-05-15 17:27:15,214 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=*'
2017-05-15 17:27:15.216 53 2017-05-15 17:27:15,216 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=AsyncLoggerRingBuffer'
2017-05-15 17:27:15.218 53 2017-05-15 17:27:15,217 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*,subtype=RingBuffer'
2017-05-15 17:27:15.220 53 2017-05-15 17:27:15,220 Thread-39 DEBUG
Registering MBean org.apache.logging.log4j2:type=c1edad85
2017-05-15 17:27:15.225 53 2017-05-15 17:27:15,225 Thread-39 DEBUG
Registering MBean org.apache.logging.log4j2:type=c1edad85,component=StatusLogger
2017-05-15 17:27:15.234 53 2017-05-15 17:27:15,234 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=ContextSelector
2017-05-15 17:27:15.238 53 2017-05-15 17:27:15,237 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkWarnLogger
2017-05-15 17:27:15.240 53 2017-05-15 17:27:15,240 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=
2017-05-15 17:27:15.242 53 2017-05-15 17:27:15,242 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkDebugLogger
2017-05-15 17:27:15.243 53 2017-05-15 17:27:15,243 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkInfoLogger
2017-05-15 17:27:15.246 53 2017-05-15 17:27:15,246 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=socket
2017-05-15 17:27:15.249 53 2017-05-15 17:27:15,249 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=SplunkAsync
2017-05-15 17:27:15.253 53 2017-05-15 17:27:15,253 Thread-39 TRACE Using
default SystemClock for timestamps.
2017-05-15 17:27:15.255 53 2017-05-15 17:27:15,254 Thread-39 TRACE Using
DummyNanoClock for nanosecond timestamps.
2017-05-15 17:27:15.256 53 2017-05-15 17:27:15,256 Thread-39 DEBUG
Reconfiguration complete for context[name=c1edad85] at URI
C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml
(org.apache.logging.log4j.core.LoggerContext@c1b7efc0) with optional
ClassLoader: null
2017-05-15 17:27:15.257 53 2017-05-15 17:27:15,257 Thread-39 DEBUG Shutdown
hook enabled. Registering a new one.
2017-05-15 17:27:15.259 53 2017-05-15 17:27:15,259 Thread-39 DEBUG
LoggerContext[name=c1edad85,
org.apache.logging.log4j.core.LoggerContext@c1b7efc0] started OK.
2017-05-15 17:27:20.568 49 [15/5/17 17:27:20:558 IST] 00000031 ManagerAdmin
I TRAS0018I: The trace state has changed. The new trace state is *=info.
2017-05-15 17:29:02.135 56 log4j:WARN No appenders could be found for
logger (net.sf.ehcache.config.ConfigurationFactory).
2017-05-15 17:29:02.136 56 log4j:WARN Please initialize the log4j system
properly.
2017-05-15 17:29:02.136 56 log4j:WARN See
http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
2017-05-15 17:29:07,135 AsyncAppender-SplunkAsync ERROR Unable to write to
stream TCP:10.52.214.26:1514 for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:29:07.137 60 2017-05-15 17:29:07,136
AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
writing to TCP:10.52.214.26:1514
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
at
org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
at
org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
... 11 more
2017-05-15 17:29:07.361 60 2017-05-15 17:29:07,360
AsyncAppender-SplunkAsync ERROR Unable to write to stream TCP:10.52.214.26:1514
for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:29:07.363 60 2017-05-15 17:29:07,361
AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
writing to TCP:10.52.214.26:1514
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
at
org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
at
org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
... 11 more
2017-05-15 17:29:41.801 247 2017-05-15 17:29:41,801
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
2017-05-15 17:31:37.844 261 2017-05-15 17:31:37,844
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
2017-05-15 17:36:40.838 60 2017-05-15 17:36:40,837
AsyncAppender-SplunkAsync ERROR Unable to write to stream TCP:10.52.214.26:1514
for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:37:10.987 293 2017-05-15 17:37:10,986
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
{code}
was:
We are facing intermittent lost of logs while sending logs to log target using
log4j2 socket appender in our application. The detailed information is as below;
Our environment:
1) In our application, we are using log4j2 (2.8.1 version jar) framework and
SocketAppender (async appender under socket appender) to send logs to Splunk (
Enterprise Logging tool) via radware(load balancer).
2) So our application connects to Radware over TCPIP socket using
SocketAppender; Radware is used to load balance load among 4 target Splunk
servers.
3) Radware Server is configured to timeout if connection is idle for one minute
(configurable at radware and set to 1 minute)
4) The configuration of log4j2 config file is as below
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="trace" monitorInterval="5">
<Appenders>
<Socket name="socket" host="10.52.214.26" port="1514"
reconnectDelayMillis="30000" immediateFail="false" bufferedIo="true"
bufferSize="204800" protocol="TCP" immediateFlush="false">
<PatternLayout></PatternLayout>
</Socket>
<Async name="SplunkAsync" bufferSize="204800">
<AppenderRef ref="socket"/>
</Async>
</Appenders>
<Loggers>
<Root level="warn">
<AppenderRef ref="SplunkAsync"/>
</Root>
<Logger name="SplunkInfoLogger" level="info" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
<Logger name="SplunkDebugLogger" level="debug" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
<Logger name="SplunkWarnLogger" level="warn" additivity="false">
<AppenderRef ref="SplunkAsync"/>
</Logger>
</Loggers>
</Configuration>
The process/steps of meeting problem:
1) Splunk servers, radware server and our application servers are up, and the
application servers send logs to radware in turn splunk servers successfully.
2) As we didn't do any operation, there is no logs come into radware in one
minute ( 1 minute as we set) and radware breaks the connection between it and
application server.
3) We did an operation so that application server will write one log. However
nothing happens, This log didn't come into radware and splunk servers at all.
4) We did a second operation so that application server will write the second
log. This time also logs did not come into radware and splunk either.
5) After counting for 30 sec (reconnectDelayMillis="30000" in log4j2 config
file) from first failed log ( i.e the log triggered after radware breaks
connection) we did a third operation so that application server will write the
third log. This time SocketAppender works well and this log came into radware
and splunk servers. This is primarily because application server is able to
re-establish connection to Radware after 30 sec as reconnectDelayMillis="30000"
I would like to know why initial logs are lost which are sent after radware
connection becomes idle. Ideally, tcp connection created by log4j2 should keep
the data in buffer when connection is broken and should send data from buffer
when reconnection is established after 30 secs (reconnectDelayMillis="30000" )
We tried setting up parameters like immediateFail="false" bufferedIo="true"
bufferSize="204800", so that data can be stored in buffer when radware times
out tcp connection and can be sent later when reconnection to radware is
established, Unfortunately which is not happening.
Are we missing any configurations because which we are facing this type of
behaviour or is it known defect.
The similar kind of issue is also observed by others and raised in apache
jira(https://issues.apache.org/jira/browse/LOG4J2-1311)
Context Log:
Listening for transport dt_socket at address: 6666
2017-05-15 17:27:05.706 1 Using jms interface URL:
file:/C:/Program%20Files/IBM/IIB/10.0.0.6/server/../common/classes/jms.jar
2017-05-15 17:27:05.724 1 Loaded JPLUG
2017-05-15 17:27:13.946 49 [15/5/17 17:27:13:397 IST] 00000031
ObjectGridRAS I CWOBJ2507I: Trace specification is set to *=off=enabled.
2017-05-15 17:27:14,671 Thread-39 DEBUG Initializing configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
2017-05-15 17:27:14.686 53 2017-05-15 17:27:14,686 Thread-39 DEBUG
Installed script engines
2017-05-15 17:27:14.754 53 2017-05-15 17:27:14,754 Thread-39 DEBUG Mozilla
Rhino Version: 1.7 release 3 PRERELEASE, Language: ECMAScript, Threading:
MULTITHREADED, Compile: true, Names: {js, rhino, JavaScript, javascript,
ECMAScript, ecmascript}
2017-05-15 17:27:14.756 53 2017-05-15 17:27:14,756 Thread-39 DEBUG
PluginManager 'Core' found 107 plugins
2017-05-15 17:27:14.757 53 2017-05-15 17:27:14,757 Thread-39 DEBUG
PluginManager 'Level' found 0 plugins
2017-05-15 17:27:14.765 53 2017-05-15 17:27:14,765 Thread-39 DEBUG 1
starting Log4j2 ConfigurationScheduler threads
2017-05-15 17:27:14.769 53 2017-05-15 17:27:14,768 Thread-39 DEBUG
PluginManager 'Lookup' found 13 plugins
2017-05-15 17:27:14.772 53 2017-05-15 17:27:14,772 Thread-39 DEBUG Building
Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2017-05-15 17:27:14.799 53 2017-05-15 17:27:14,798 Thread-39 TRACE
TypeConverterRegistry initializing.
2017-05-15 17:27:14.800 53 2017-05-15 17:27:14,800 Thread-39 DEBUG
PluginManager 'TypeConverter' found 23 plugins
2017-05-15 17:27:14.834 53 2017-05-15 17:27:14,834 Thread-39 DEBUG
PatternLayout$Builder(pattern="null", PatternSelector=null,
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Replace=null,
charset="null", alwaysWriteExceptions="null", noConsoleNoAnsi="null",
header="null", footer="null")
2017-05-15 17:27:14.836 53 2017-05-15 17:27:14,836 Thread-39 DEBUG
PluginManager 'Converter' found 41 plugins
2017-05-15 17:27:14.838 53 2017-05-15 17:27:14,838 Thread-39 DEBUG Building
Plugin[name=appender,
class=org.apache.logging.log4j.core.appender.SocketAppender].
2017-05-15 17:27:14.862 53 2017-05-15 17:27:14,862 Thread-39 DEBUG
SocketAppender$Builder(advertise="null",
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
connectTimeoutMillis="null", host="10.52.214.26", immediateFail="false",
port="1514", protocol="TCP", reconnectDelayMillis="30000",
SslConfiguration=null, bufferedIo="true", bufferSize="204800",
immediateFlush="false", ignoreExceptions="null", PatternLayout(%m%n),
name="socket", Filter=null)
2017-05-15 17:27:15.053 53 2017-05-15 17:27:15,052 Thread-39 DEBUG Starting
TcpSocketManager TCP:10.52.214.26:1514
2017-05-15 17:27:15.054 53 2017-05-15 17:27:15,054 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.066 53 2017-05-15 17:27:15,066 Thread-39 DEBUG
createAppenderRef(ref="socket", level="null", Filter=null)
2017-05-15 17:27:15.070 53 2017-05-15 17:27:15,070 Thread-39 DEBUG Building
Plugin[name=appender,
class=org.apache.logging.log4j.core.appender.AsyncAppender].
2017-05-15 17:27:15.081 53 2017-05-15 17:27:15,081 Thread-39 DEBUG
AsyncAppender$Builder(={socket}, errorRef="null", blocking="null",
shutdownTimeout="null", bufferSize="204800", name="SplunkAsync",
includeLocation="null", Filter=null,
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
ignoreExceptions="null", BlockingQueueFactory=null)
2017-05-15 17:27:15.084 53 2017-05-15 17:27:15,083 Thread-39 DEBUG Building
Plugin[name=appenders,
class=org.apache.logging.log4j.core.config.AppendersPlugin].
2017-05-15 17:27:15.086 53 2017-05-15 17:27:15,085 Thread-39 DEBUG
createAppenders(={socket, SplunkAsync})
2017-05-15 17:27:15.087 53 2017-05-15 17:27:15,087 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.089 53 2017-05-15 17:27:15,089 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.091 53 2017-05-15 17:27:15,090 Thread-39 DEBUG Building
Plugin[name=root,
class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2017-05-15 17:27:15.094 53 2017-05-15 17:27:15,094 Thread-39 DEBUG
createLogger(additivity="null", level="WARN", includeLocation="null",
={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.115 53 2017-05-15 17:27:15,113 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.120 53 2017-05-15 17:27:15,120 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.123 53 2017-05-15 17:27:15,123 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.128 53 2017-05-15 17:27:15,127 Thread-39 DEBUG
createLogger(additivity="false", level="INFO", name="SplunkInfoLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.130 53 2017-05-15 17:27:15,130 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.133 53 2017-05-15 17:27:15,132 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.134 53 2017-05-15 17:27:15,134 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.147 53 2017-05-15 17:27:15,146 Thread-39 DEBUG
createLogger(additivity="false", level="DEBUG", name="SplunkDebugLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.148 53 2017-05-15 17:27:15,148 Thread-39 DEBUG Building
Plugin[name=AppenderRef,
class=org.apache.logging.log4j.core.config.AppenderRef].
2017-05-15 17:27:15.151 53 2017-05-15 17:27:15,150 Thread-39 DEBUG
createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
2017-05-15 17:27:15.152 53 2017-05-15 17:27:15,152 Thread-39 DEBUG Building
Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2017-05-15 17:27:15.156 53 2017-05-15 17:27:15,156 Thread-39 DEBUG
createLogger(additivity="false", level="WARN", name="SplunkWarnLogger",
includeLocation="null", ={SplunkAsync}, ={},
Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
2017-05-15 17:27:15.158 53 2017-05-15 17:27:15,157 Thread-39 DEBUG Building
Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2017-05-15 17:27:15.165 53 2017-05-15 17:27:15,165 Thread-39 DEBUG
createLoggers(={root, SplunkInfoLogger, SplunkDebugLogger, SplunkWarnLogger})
2017-05-15 17:27:15.167 53 2017-05-15 17:27:15,167 Thread-39 DEBUG
Configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
initialized
2017-05-15 17:27:15.169 53 2017-05-15 17:27:15,168 Thread-39 DEBUG Starting
configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
2017-05-15 17:27:15.178 53 2017-05-15 17:27:15,178 Thread-39 DEBUG Started
configuration
XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml] OK.
2017-05-15 17:27:15.180 53 2017-05-15 17:27:15,180 Thread-39 TRACE Stopping
org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c...
2017-05-15 17:27:15.181 53 2017-05-15 17:27:15,181 Thread-39 TRACE
DefaultConfiguration notified 1 ReliabilityStrategies that config will be
stopped.
2017-05-15 17:27:15.184 53 2017-05-15 17:27:15,184 Thread-39 TRACE
DefaultConfiguration stopping root LoggerConfig.
2017-05-15 17:27:15.185 53 2017-05-15 17:27:15,185 Thread-39 TRACE
DefaultConfiguration notifying ReliabilityStrategies that appenders will be
stopped.
2017-05-15 17:27:15.187 53 2017-05-15 17:27:15,186 Thread-39 TRACE
DefaultConfiguration stopping remaining Appenders.
2017-05-15 17:27:15.188 53 2017-05-15 17:27:15,187 Thread-39 DEBUG Shutting
down OutputStreamManager SYSTEM_OUT.false.false-1
2017-05-15 17:27:15.189 53 2017-05-15 17:27:15,189 Thread-39 DEBUG Shut
down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2017-05-15 17:27:15.190 53 2017-05-15 17:27:15,190 Thread-39 TRACE
DefaultConfiguration stopped 1 remaining Appenders.
2017-05-15 17:27:15.191 53 2017-05-15 17:27:15,191 Thread-39 TRACE
DefaultConfiguration cleaning Appenders from 1 LoggerConfigs.
2017-05-15 17:27:15.193 53 2017-05-15 17:27:15,193 Thread-39 DEBUG Stopped
org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c OK
2017-05-15 17:27:15.198 53 2017-05-15 17:27:15,197 Thread-39 TRACE
Reregistering MBeans after reconfigure.
Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@7a7e9cb6
2017-05-15 17:27:15.199 53 2017-05-15 17:27:15,199 Thread-39 TRACE
Reregistering context (1/1): 'c1edad85'
org.apache.logging.log4j.core.LoggerContext@c1b7efc0
2017-05-15 17:27:15.200 53 2017-05-15 17:27:15,200 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85'
2017-05-15 17:27:15.202 53 2017-05-15 17:27:15,202 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=StatusLogger'
2017-05-15 17:27:15.203 53 2017-05-15 17:27:15,203 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=ContextSelector'
2017-05-15 17:27:15.205 53 2017-05-15 17:27:15,205 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*'
2017-05-15 17:27:15.213 53 2017-05-15 17:27:15,213 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=*'
2017-05-15 17:27:15.215 53 2017-05-15 17:27:15,214 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=*'
2017-05-15 17:27:15.216 53 2017-05-15 17:27:15,216 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=AsyncLoggerRingBuffer'
2017-05-15 17:27:15.218 53 2017-05-15 17:27:15,217 Thread-39 TRACE
Unregistering but no MBeans found matching
'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*,subtype=RingBuffer'
2017-05-15 17:27:15.220 53 2017-05-15 17:27:15,220 Thread-39 DEBUG
Registering MBean org.apache.logging.log4j2:type=c1edad85
2017-05-15 17:27:15.225 53 2017-05-15 17:27:15,225 Thread-39 DEBUG
Registering MBean org.apache.logging.log4j2:type=c1edad85,component=StatusLogger
2017-05-15 17:27:15.234 53 2017-05-15 17:27:15,234 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=ContextSelector
2017-05-15 17:27:15.238 53 2017-05-15 17:27:15,237 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkWarnLogger
2017-05-15 17:27:15.240 53 2017-05-15 17:27:15,240 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=
2017-05-15 17:27:15.242 53 2017-05-15 17:27:15,242 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkDebugLogger
2017-05-15 17:27:15.243 53 2017-05-15 17:27:15,243 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkInfoLogger
2017-05-15 17:27:15.246 53 2017-05-15 17:27:15,246 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=socket
2017-05-15 17:27:15.249 53 2017-05-15 17:27:15,249 Thread-39 DEBUG
Registering MBean
org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=SplunkAsync
2017-05-15 17:27:15.253 53 2017-05-15 17:27:15,253 Thread-39 TRACE Using
default SystemClock for timestamps.
2017-05-15 17:27:15.255 53 2017-05-15 17:27:15,254 Thread-39 TRACE Using
DummyNanoClock for nanosecond timestamps.
2017-05-15 17:27:15.256 53 2017-05-15 17:27:15,256 Thread-39 DEBUG
Reconfiguration complete for context[name=c1edad85] at URI
C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml
(org.apache.logging.log4j.core.LoggerContext@c1b7efc0) with optional
ClassLoader: null
2017-05-15 17:27:15.257 53 2017-05-15 17:27:15,257 Thread-39 DEBUG Shutdown
hook enabled. Registering a new one.
2017-05-15 17:27:15.259 53 2017-05-15 17:27:15,259 Thread-39 DEBUG
LoggerContext[name=c1edad85,
org.apache.logging.log4j.core.LoggerContext@c1b7efc0] started OK.
2017-05-15 17:27:20.568 49 [15/5/17 17:27:20:558 IST] 00000031 ManagerAdmin
I TRAS0018I: The trace state has changed. The new trace state is *=info.
2017-05-15 17:29:02.135 56 log4j:WARN No appenders could be found for
logger (net.sf.ehcache.config.ConfigurationFactory).
2017-05-15 17:29:02.136 56 log4j:WARN Please initialize the log4j system
properly.
2017-05-15 17:29:02.136 56 log4j:WARN See
http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
2017-05-15 17:29:07,135 AsyncAppender-SplunkAsync ERROR Unable to write to
stream TCP:10.52.214.26:1514 for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:29:07.137 60 2017-05-15 17:29:07,136
AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
writing to TCP:10.52.214.26:1514
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
at
org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
at
org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
... 11 more
2017-05-15 17:29:07.361 60 2017-05-15 17:29:07,360
AsyncAppender-SplunkAsync ERROR Unable to write to stream TCP:10.52.214.26:1514
for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:29:07.363 60 2017-05-15 17:29:07,361
AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
writing to TCP:10.52.214.26:1514
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
at
org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
at
org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
at
org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
at
org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
at
org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
... 11 more
2017-05-15 17:29:41.801 247 2017-05-15 17:29:41,801
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
2017-05-15 17:31:37.844 261 2017-05-15 17:31:37,844
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
2017-05-15 17:36:40.838 60 2017-05-15 17:36:40,837
AsyncAppender-SplunkAsync ERROR Unable to write to stream TCP:10.52.214.26:1514
for appender socket:
org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing
to TCP:10.52.214.26:1514
2017-05-15 17:37:10.987 293 2017-05-15 17:37:10,986
Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
reestablished.
> Issues with log4j2 socket appender - Logs are lost when target application
> closes the tcp connection after idle time
> --------------------------------------------------------------------------------------------------------------------
>
> Key: LOG4J2-1918
> URL: https://issues.apache.org/jira/browse/LOG4J2-1918
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.7, 2.8.1, 2.8.2
> Environment: In our application, we are using log4j2 (2.8.1 version
> jar) framework and SocketAppender (async appender under socket appender) to
> send logs to Splunk ( Enterprise Logging tool) via radware(load balancer)
> using tcp protocol.
> Reporter: Girish
> Original Estimate: 504h
> Remaining Estimate: 504h
>
> We are facing intermittent lost of logs while sending logs to log target
> using log4j2 socket appender in our application. The detailed information is
> as below;
>
> Our environment:
> 1) In our application, we are using log4j2 (2.8.1 version jar) framework and
> SocketAppender (async appender under socket appender) to send logs to Splunk
> ( Enterprise Logging tool) via radware(load balancer).
> 2) So our application connects to Radware over TCPIP socket using
> SocketAppender; Radware is used to load balance load among 4 target Splunk
> servers.
> 3) Radware Server is configured to timeout if connection is idle for one
> minute (configurable at radware and set to 1 minute)
> 4) The configuration of log4j2 config file is as below
>
> {code}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration status="trace" monitorInterval="5">
> <Appenders>
> <Socket name="socket" host="10.52.214.26" port="1514"
> reconnectDelayMillis="30000" immediateFail="false" bufferedIo="true"
> bufferSize="204800" protocol="TCP" immediateFlush="false">
> <PatternLayout></PatternLayout>
> </Socket>
> <Async name="SplunkAsync" bufferSize="204800">
> <AppenderRef ref="socket"/>
> </Async>
> </Appenders>
> <Loggers>
> <Root level="warn">
> <AppenderRef ref="SplunkAsync"/>
> </Root>
> <Logger name="SplunkInfoLogger" level="info" additivity="false">
> <AppenderRef ref="SplunkAsync"/>
> </Logger>
> <Logger name="SplunkDebugLogger" level="debug" additivity="false">
> <AppenderRef ref="SplunkAsync"/>
> </Logger>
> <Logger name="SplunkWarnLogger" level="warn" additivity="false">
> <AppenderRef ref="SplunkAsync"/>
> </Logger>
> </Loggers>
> </Configuration>
> {code}
>
> The process/steps of meeting problem:
> 1) Splunk servers, radware server and our application servers are up, and the
> application servers send logs to radware in turn splunk servers successfully.
> 2) As we didn't do any operation, there is no logs come into radware in one
> minute ( 1 minute as we set) and radware breaks the connection between it and
> application server.
> 3) We did an operation so that application server will write one log. However
> nothing happens, This log didn't come into radware and splunk servers at all.
> 4) We did a second operation so that application server will write the second
> log. This time also logs did not come into radware and splunk either.
> 5) After counting for 30 sec (reconnectDelayMillis="30000" in log4j2 config
> file) from first failed log ( i.e the log triggered after radware breaks
> connection) we did a third operation so that application server will write
> the third log. This time SocketAppender works well and this log came into
> radware and splunk servers. This is primarily because application server is
> able to re-establish connection to Radware after 30 sec as
> reconnectDelayMillis="30000"
>
> I would like to know why initial logs are lost which are sent after radware
> connection becomes idle. Ideally, tcp connection created by log4j2 should
> keep the data in buffer when connection is broken and should send data from
> buffer when reconnection is established after 30 secs
> (reconnectDelayMillis="30000" )
>
> We tried setting up parameters like immediateFail="false" bufferedIo="true"
> bufferSize="204800", so that data can be stored in buffer when radware times
> out tcp connection and can be sent later when reconnection to radware is
> established, Unfortunately which is not happening.
>
> Are we missing any configurations because which we are facing this type of
> behaviour or is it known defect.
>
> The similar kind of issue is also observed by others and raised in apache
> jira(https://issues.apache.org/jira/browse/LOG4J2-1311)
> Context Log:
> {code}
> Listening for transport dt_socket at address: 6666
> 2017-05-15 17:27:05.706 1 Using jms interface URL:
> file:/C:/Program%20Files/IBM/IIB/10.0.0.6/server/../common/classes/jms.jar
> 2017-05-15 17:27:05.724 1 Loaded JPLUG
> 2017-05-15 17:27:13.946 49 [15/5/17 17:27:13:397 IST] 00000031
> ObjectGridRAS I CWOBJ2507I: Trace specification is set to *=off=enabled.
> 2017-05-15 17:27:14,671 Thread-39 DEBUG Initializing configuration
> XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
> 2017-05-15 17:27:14.686 53 2017-05-15 17:27:14,686 Thread-39 DEBUG
> Installed script engines
> 2017-05-15 17:27:14.754 53 2017-05-15 17:27:14,754 Thread-39 DEBUG
> Mozilla Rhino Version: 1.7 release 3 PRERELEASE, Language: ECMAScript,
> Threading: MULTITHREADED, Compile: true, Names: {js, rhino, JavaScript,
> javascript, ECMAScript, ecmascript}
> 2017-05-15 17:27:14.756 53 2017-05-15 17:27:14,756 Thread-39 DEBUG
> PluginManager 'Core' found 107 plugins
> 2017-05-15 17:27:14.757 53 2017-05-15 17:27:14,757 Thread-39 DEBUG
> PluginManager 'Level' found 0 plugins
> 2017-05-15 17:27:14.765 53 2017-05-15 17:27:14,765 Thread-39 DEBUG 1
> starting Log4j2 ConfigurationScheduler threads
> 2017-05-15 17:27:14.769 53 2017-05-15 17:27:14,768 Thread-39 DEBUG
> PluginManager 'Lookup' found 13 plugins
> 2017-05-15 17:27:14.772 53 2017-05-15 17:27:14,772 Thread-39 DEBUG
> Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2017-05-15 17:27:14.799 53 2017-05-15 17:27:14,798 Thread-39 TRACE
> TypeConverterRegistry initializing.
> 2017-05-15 17:27:14.800 53 2017-05-15 17:27:14,800 Thread-39 DEBUG
> PluginManager 'TypeConverter' found 23 plugins
> 2017-05-15 17:27:14.834 53 2017-05-15 17:27:14,834 Thread-39 DEBUG
> PatternLayout$Builder(pattern="null", PatternSelector=null,
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Replace=null,
> charset="null", alwaysWriteExceptions="null", noConsoleNoAnsi="null",
> header="null", footer="null")
> 2017-05-15 17:27:14.836 53 2017-05-15 17:27:14,836 Thread-39 DEBUG
> PluginManager 'Converter' found 41 plugins
> 2017-05-15 17:27:14.838 53 2017-05-15 17:27:14,838 Thread-39 DEBUG
> Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.SocketAppender].
> 2017-05-15 17:27:14.862 53 2017-05-15 17:27:14,862 Thread-39 DEBUG
> SocketAppender$Builder(advertise="null",
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
> connectTimeoutMillis="null", host="10.52.214.26", immediateFail="false",
> port="1514", protocol="TCP", reconnectDelayMillis="30000",
> SslConfiguration=null, bufferedIo="true", bufferSize="204800",
> immediateFlush="false", ignoreExceptions="null", PatternLayout(%m%n),
> name="socket", Filter=null)
> 2017-05-15 17:27:15.053 53 2017-05-15 17:27:15,052 Thread-39 DEBUG
> Starting TcpSocketManager TCP:10.52.214.26:1514
> 2017-05-15 17:27:15.054 53 2017-05-15 17:27:15,054 Thread-39 DEBUG
> Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2017-05-15 17:27:15.066 53 2017-05-15 17:27:15,066 Thread-39 DEBUG
> createAppenderRef(ref="socket", level="null", Filter=null)
> 2017-05-15 17:27:15.070 53 2017-05-15 17:27:15,070 Thread-39 DEBUG
> Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.AsyncAppender].
> 2017-05-15 17:27:15.081 53 2017-05-15 17:27:15,081 Thread-39 DEBUG
> AsyncAppender$Builder(={socket}, errorRef="null", blocking="null",
> shutdownTimeout="null", bufferSize="204800", name="SplunkAsync",
> includeLocation="null", Filter=null,
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml),
> ignoreExceptions="null", BlockingQueueFactory=null)
> 2017-05-15 17:27:15.084 53 2017-05-15 17:27:15,083 Thread-39 DEBUG
> Building Plugin[name=appenders,
> class=org.apache.logging.log4j.core.config.AppendersPlugin].
> 2017-05-15 17:27:15.086 53 2017-05-15 17:27:15,085 Thread-39 DEBUG
> createAppenders(={socket, SplunkAsync})
> 2017-05-15 17:27:15.087 53 2017-05-15 17:27:15,087 Thread-39 DEBUG
> Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2017-05-15 17:27:15.089 53 2017-05-15 17:27:15,089 Thread-39 DEBUG
> createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
> 2017-05-15 17:27:15.091 53 2017-05-15 17:27:15,090 Thread-39 DEBUG
> Building Plugin[name=root,
> class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
> 2017-05-15 17:27:15.094 53 2017-05-15 17:27:15,094 Thread-39 DEBUG
> createLogger(additivity="null", level="WARN", includeLocation="null",
> ={SplunkAsync}, ={},
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
> 2017-05-15 17:27:15.115 53 2017-05-15 17:27:15,113 Thread-39 DEBUG
> Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2017-05-15 17:27:15.120 53 2017-05-15 17:27:15,120 Thread-39 DEBUG
> createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
> 2017-05-15 17:27:15.123 53 2017-05-15 17:27:15,123 Thread-39 DEBUG
> Building Plugin[name=logger,
> class=org.apache.logging.log4j.core.config.LoggerConfig].
> 2017-05-15 17:27:15.128 53 2017-05-15 17:27:15,127 Thread-39 DEBUG
> createLogger(additivity="false", level="INFO", name="SplunkInfoLogger",
> includeLocation="null", ={SplunkAsync}, ={},
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
> 2017-05-15 17:27:15.130 53 2017-05-15 17:27:15,130 Thread-39 DEBUG
> Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2017-05-15 17:27:15.133 53 2017-05-15 17:27:15,132 Thread-39 DEBUG
> createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
> 2017-05-15 17:27:15.134 53 2017-05-15 17:27:15,134 Thread-39 DEBUG
> Building Plugin[name=logger,
> class=org.apache.logging.log4j.core.config.LoggerConfig].
> 2017-05-15 17:27:15.147 53 2017-05-15 17:27:15,146 Thread-39 DEBUG
> createLogger(additivity="false", level="DEBUG", name="SplunkDebugLogger",
> includeLocation="null", ={SplunkAsync}, ={},
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
> 2017-05-15 17:27:15.148 53 2017-05-15 17:27:15,148 Thread-39 DEBUG
> Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2017-05-15 17:27:15.151 53 2017-05-15 17:27:15,150 Thread-39 DEBUG
> createAppenderRef(ref="SplunkAsync", level="null", Filter=null)
> 2017-05-15 17:27:15.152 53 2017-05-15 17:27:15,152 Thread-39 DEBUG
> Building Plugin[name=logger,
> class=org.apache.logging.log4j.core.config.LoggerConfig].
> 2017-05-15 17:27:15.156 53 2017-05-15 17:27:15,156 Thread-39 DEBUG
> createLogger(additivity="false", level="WARN", name="SplunkWarnLogger",
> includeLocation="null", ={SplunkAsync}, ={},
> Configuration(C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml), Filter=null)
> 2017-05-15 17:27:15.158 53 2017-05-15 17:27:15,157 Thread-39 DEBUG
> Building Plugin[name=loggers,
> class=org.apache.logging.log4j.core.config.LoggersPlugin].
> 2017-05-15 17:27:15.165 53 2017-05-15 17:27:15,165 Thread-39 DEBUG
> createLoggers(={root, SplunkInfoLogger, SplunkDebugLogger, SplunkWarnLogger})
> 2017-05-15 17:27:15.167 53 2017-05-15 17:27:15,167 Thread-39 DEBUG
> Configuration
> XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
> initialized
> 2017-05-15 17:27:15.169 53 2017-05-15 17:27:15,168 Thread-39 DEBUG
> Starting configuration
> XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml]
> 2017-05-15 17:27:15.178 53 2017-05-15 17:27:15,178 Thread-39 DEBUG
> Started configuration
> XmlConfiguration[location=C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml] OK.
> 2017-05-15 17:27:15.180 53 2017-05-15 17:27:15,180 Thread-39 TRACE
> Stopping org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c...
> 2017-05-15 17:27:15.181 53 2017-05-15 17:27:15,181 Thread-39 TRACE
> DefaultConfiguration notified 1 ReliabilityStrategies that config will be
> stopped.
> 2017-05-15 17:27:15.184 53 2017-05-15 17:27:15,184 Thread-39 TRACE
> DefaultConfiguration stopping root LoggerConfig.
> 2017-05-15 17:27:15.185 53 2017-05-15 17:27:15,185 Thread-39 TRACE
> DefaultConfiguration notifying ReliabilityStrategies that appenders will be
> stopped.
> 2017-05-15 17:27:15.187 53 2017-05-15 17:27:15,186 Thread-39 TRACE
> DefaultConfiguration stopping remaining Appenders.
> 2017-05-15 17:27:15.188 53 2017-05-15 17:27:15,187 Thread-39 DEBUG
> Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
> 2017-05-15 17:27:15.189 53 2017-05-15 17:27:15,189 Thread-39 DEBUG Shut
> down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released:
> true
> 2017-05-15 17:27:15.190 53 2017-05-15 17:27:15,190 Thread-39 TRACE
> DefaultConfiguration stopped 1 remaining Appenders.
> 2017-05-15 17:27:15.191 53 2017-05-15 17:27:15,191 Thread-39 TRACE
> DefaultConfiguration cleaning Appenders from 1 LoggerConfigs.
> 2017-05-15 17:27:15.193 53 2017-05-15 17:27:15,193 Thread-39 DEBUG
> Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@ce510e6c OK
> 2017-05-15 17:27:15.198 53 2017-05-15 17:27:15,197 Thread-39 TRACE
> Reregistering MBeans after reconfigure.
> Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@7a7e9cb6
> 2017-05-15 17:27:15.199 53 2017-05-15 17:27:15,199 Thread-39 TRACE
> Reregistering context (1/1): 'c1edad85'
> org.apache.logging.log4j.core.LoggerContext@c1b7efc0
> 2017-05-15 17:27:15.200 53 2017-05-15 17:27:15,200 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85'
> 2017-05-15 17:27:15.202 53 2017-05-15 17:27:15,202 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=StatusLogger'
> 2017-05-15 17:27:15.203 53 2017-05-15 17:27:15,203 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=ContextSelector'
> 2017-05-15 17:27:15.205 53 2017-05-15 17:27:15,205 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*'
> 2017-05-15 17:27:15.213 53 2017-05-15 17:27:15,213 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=*'
> 2017-05-15 17:27:15.215 53 2017-05-15 17:27:15,214 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=*'
> 2017-05-15 17:27:15.216 53 2017-05-15 17:27:15,216 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=AsyncLoggerRingBuffer'
> 2017-05-15 17:27:15.218 53 2017-05-15 17:27:15,217 Thread-39 TRACE
> Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=*,subtype=RingBuffer'
> 2017-05-15 17:27:15.220 53 2017-05-15 17:27:15,220 Thread-39 DEBUG
> Registering MBean org.apache.logging.log4j2:type=c1edad85
> 2017-05-15 17:27:15.225 53 2017-05-15 17:27:15,225 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=StatusLogger
> 2017-05-15 17:27:15.234 53 2017-05-15 17:27:15,234 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=ContextSelector
> 2017-05-15 17:27:15.238 53 2017-05-15 17:27:15,237 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkWarnLogger
> 2017-05-15 17:27:15.240 53 2017-05-15 17:27:15,240 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=
> 2017-05-15 17:27:15.242 53 2017-05-15 17:27:15,242 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkDebugLogger
> 2017-05-15 17:27:15.243 53 2017-05-15 17:27:15,243 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=Loggers,name=SplunkInfoLogger
> 2017-05-15 17:27:15.246 53 2017-05-15 17:27:15,246 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=Appenders,name=socket
> 2017-05-15 17:27:15.249 53 2017-05-15 17:27:15,249 Thread-39 DEBUG
> Registering MBean
> org.apache.logging.log4j2:type=c1edad85,component=AsyncAppenders,name=SplunkAsync
> 2017-05-15 17:27:15.253 53 2017-05-15 17:27:15,253 Thread-39 TRACE Using
> default SystemClock for timestamps.
> 2017-05-15 17:27:15.255 53 2017-05-15 17:27:15,254 Thread-39 TRACE Using
> DummyNanoClock for nanosecond timestamps.
> 2017-05-15 17:27:15.256 53 2017-05-15 17:27:15,256 Thread-39 DEBUG
> Reconfiguration complete for context[name=c1edad85] at URI
> C:\ProgramData\IBM\MQSI\common\wsrr\log4j2.xml
> (org.apache.logging.log4j.core.LoggerContext@c1b7efc0) with optional
> ClassLoader: null
> 2017-05-15 17:27:15.257 53 2017-05-15 17:27:15,257 Thread-39 DEBUG
> Shutdown hook enabled. Registering a new one.
> 2017-05-15 17:27:15.259 53 2017-05-15 17:27:15,259 Thread-39 DEBUG
> LoggerContext[name=c1edad85,
> org.apache.logging.log4j.core.LoggerContext@c1b7efc0] started OK.
> 2017-05-15 17:27:20.568 49 [15/5/17 17:27:20:558 IST] 00000031
> ManagerAdmin I TRAS0018I: The trace state has changed. The new trace state
> is *=info.
> 2017-05-15 17:29:02.135 56 log4j:WARN No appenders could be found for
> logger (net.sf.ehcache.config.ConfigurationFactory).
> 2017-05-15 17:29:02.136 56 log4j:WARN Please initialize the log4j system
> properly.
> 2017-05-15 17:29:02.136 56 log4j:WARN See
> http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
> 2017-05-15 17:29:07,135 AsyncAppender-SplunkAsync ERROR Unable to write to
> stream TCP:10.52.214.26:1514 for appender socket:
> org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to TCP:10.52.214.26:1514
> 2017-05-15 17:29:07.137 60 2017-05-15 17:29:07,136
> AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
> socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to TCP:10.52.214.26:1514
> at
> org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
> at
> org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
> at
> org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at
> org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
> at
> org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
> Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
> socket write error
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
> at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
> at
> org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
> ... 11 more
> 2017-05-15 17:29:07.361 60 2017-05-15 17:29:07,360
> AsyncAppender-SplunkAsync ERROR Unable to write to stream
> TCP:10.52.214.26:1514 for appender socket:
> org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to TCP:10.52.214.26:1514
> 2017-05-15 17:29:07.363 60 2017-05-15 17:29:07,361
> AsyncAppender-SplunkAsync ERROR An exception occurred processing Appender
> socket org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to TCP:10.52.214.26:1514
> at
> org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:143)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:197)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.writeByteArrayToManager(AbstractOutputStreamAppender.java:185)
> at
> org.apache.logging.log4j.core.appender.SocketAppender.directEncodeEvent(SocketAppender.java:424)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
> at
> org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at
> org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:451)
> at
> org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:404)
> Caused by: java.net.SocketException: Unrecognized Windows Sockets error: 0:
> socket write error
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:125)
> at java.net.SocketOutputStream.write(SocketOutputStream.java:171)
> at
> org.apache.logging.log4j.core.net.TcpSocketManager.write(TcpSocketManager.java:133)
> ... 11 more
> 2017-05-15 17:29:41.801 247 2017-05-15 17:29:41,801
> Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
> reestablished.
> 2017-05-15 17:31:37.844 261 2017-05-15 17:31:37,844
> Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
> reestablished.
> 2017-05-15 17:36:40.838 60 2017-05-15 17:36:40,837
> AsyncAppender-SplunkAsync ERROR Unable to write to stream
> TCP:10.52.214.26:1514 for appender socket:
> org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to TCP:10.52.214.26:1514
> 2017-05-15 17:37:10.987 293 2017-05-15 17:37:10,986
> Log4j2-TcpSocketManager-Reconnector DEBUG Connection to 10.52.214.26:1514
> reestablished.
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
