logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mauro Rocco (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-1200) Kill process with Socket Appender causes flood of Connection-Reset logs
Date Thu, 26 Nov 2015 16:55:11 GMT

    [ https://issues.apache.org/jira/browse/LOG4J2-1200?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15029101#comment-15029101
] 

Mauro Rocco commented on LOG4J2-1200:
-------------------------------------

Hi,
I had the same problem and I think that the mistake resides in the file org.apache.logging.log4j.core.net.server.InputStreamLogEventBridge,
in fact the method logEvents has a throws declaration of IOException but all the method body
is surrounded from a try catch block that catches IOException and logs it. In this way the
method is never throwing the IOException and therefore the SockerServer objects are not removing
the handlers.
The solution should just be as follow, remove the try catch.
{code:title=InputStreamLogEventBridge.java|borderStyle=solid}
public void logEvents(final InputStream inputStream, final LogEventListener logEventListener)
throws IOException {
    String workingText = Strings.EMPTY;
    //try {
        // Allocate buffer once
        final byte[] buffer = new byte[bufferSize];
        String textRemains = workingText = Strings.EMPTY;
        while (true) {
            // Process until the stream is EOF.
            final int streamReadLength = inputStream.read(buffer);
            if (streamReadLength == END) {
                // The input stream is EOF
                break;
            }
            final String text = workingText = textRemains + new String(buffer, 0, streamReadLength,
charset);
            int beginIndex = 0;
            while (true) {
                // Extract and log all XML events in the buffer
                final int[] pair = getEventIndices(text, beginIndex);
                final int eventStartMarkerIndex = pair[0];
                if (eventStartMarkerIndex < 0) {
                    // No more events or partial XML only in the buffer.
                    // Save the unprocessed string part
                    textRemains = text.substring(beginIndex);
                    break;
                }
                final int eventEndMarkerIndex = pair[1];
                if (eventEndMarkerIndex > 0) {
                    final int eventEndXmlIndex = eventEndMarkerIndex + eventEndMarker.length();
                    final String textEvent = workingText = text.substring(eventStartMarkerIndex,
eventEndXmlIndex);
                    final LogEvent logEvent = unmarshal(textEvent);
                    logEventListener.log(logEvent);
                    beginIndex = eventEndXmlIndex;
                } else {
                    // No more events or partial XML only in the buffer.
                    // Save the unprocessed string part
                    textRemains = text.substring(beginIndex);
                    break;
                }
            }
        }
   // } catch (final IOException ex) {
  //      logger.error(workingText, ex);
  //  }
}
{code}

> Kill process with Socket Appender causes flood of Connection-Reset logs
> -----------------------------------------------------------------------
>
>                 Key: LOG4J2-1200
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1200
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders, Core
>    Affects Versions: 2.4.1
>         Environment: win64 java8 osgi
>            Reporter: Hüseyin Kartal
>
> Hi,
> we use primary the SocketAppender to send log messages to a server instance. The server
instance is based on the TcpSocketServer and is started as follows:
> h1. Server Context
> h2. Startup
> {code}
> new TcpSocketServer<>(9500, new JsonInputStreamLogEventBridge()).startNewThread();
> {code}
> h2. Configuration
> {code:xml}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration monitorInterval="0" strict="true" name="XMLConfig" status="error" shutdownHook="enable"
xmlns="http://jakarta.apache.org/log4j2/config" xmlns:events="http://jakarta.apache.org/log4j2/events"
xmlns:levels="http://jakarta.apache.org/log4j2/levels" xmlns:xi="http://www.w3.org/2001/XInclude"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://jakarta.apache.org/log4j2/config
Log4j-config.xsd http://jakarta.apache.org/log4j2/events Log4j-events.xsd http://jakarta.apache.org/log4j2/levels
Log4j-levels.xsd">
> 	<xi:include href="log4j2-properties.xml" />
> 	<Appenders>
> 		<Appender type="Console" name="OUT">
> 			<Layout Type="PatternLayout" Pattern="${sys:log.application}: ${pattern}" />
> 		</Appender>
> 		<Appender type="RollingRandomAccessFile" name="OUT-FILE" fileName="${file.name.out}${file.suffix}"
filePattern="${file.name.out}-%2i${file.suffix}">
> 			<Layout Type="PatternLayout" Pattern="${pattern}" />
> 			<Policies>
> 				<SizeBasedTriggeringPolicy size="${sizeBasedTriggeringPolicy.size}" />
> 			</Policies>
> 			<DefaultRolloverStrategy max="${defaultRolloverStrategy.max}" fileIndex="min" />
> 		</Appender>
> 		<Appender type="RollingRandomAccessFile" name="ERR-FILE" fileName="${file.name.err}${file.suffix}"
filePattern="${file.name.err}-%2i${file.suffix}">
> 			<Layout Type="PatternLayout" Pattern="${pattern}" />
> 			<Policies>
> 				<SizeBasedTriggeringPolicy size="${sizeBasedTriggeringPolicy.size}" />
> 			</Policies>
> 			<DefaultRolloverStrategy max="${defaultRolloverStrategy.max}" fileIndex="min" />
> 		</Appender>
> 		<Async name="ASYNC-OUT">
> 			<AppenderRef ref="OUT" />
> 		</Async>
> 		<Async name="ASYNC-OUT-FILE">
> 			<AppenderRef ref="OUT-FILE" />
> 		</Async>
> 	</Appenders>
> 	<Loggers>
> 		<asyncRoot level="all">
> 			<AppenderRef ref="ASYNC-OUT" />
> 			<AppenderRef ref="ASYNC-OUT-FILE" />
> 		</asyncRoot>
> 		<asyncLogger name="com" level="error" />
> 		<asyncLogger name="org" level="error" />
> 		<asyncLogger name="javax" level="error" />
> 	</Loggers>
> </Configuration>
> {code}
> h1. Client context
> h2. Configuration
> {code:xml}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration monitorInterval="0" strict="true" name="XMLConfig" status="fatal" shutdownHook="enable"
xmlns="http://jakarta.apache.org/log4j2/config" xmlns:events="http://jakarta.apache.org/log4j2/events"
xmlns:levels="http://jakarta.apache.org/log4j2/levels" xmlns:xi="http://www.w3.org/2001/XInclude"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://jakarta.apache.org/log4j2/config
Log4j-config.xsd http://jakarta.apache.org/log4j2/events Log4j-events.xsd http://jakarta.apache.org/log4j2/levels
Log4j-levels.xsd">
> 	<xi:include href="log4j2-properties.xml" />
> 	<Appenders>
> 		<Appender type="Socket" name="OUT-SOCKET" host="${sys:log.host}" port="${sys:log.port}"
protocol="${sys:log.protocol}" ignoreExceptions="false">
> 			<Layout type="JsonLayout" compact="true" eventEol="true" complete="true" properties="true"
/>
> 		</Appender>
> 		<Appender type="Failover" name="OUT-FAIL" primary="OUT-SOCKET">
> 			<Failovers>
> 				<Appender type="RollingRandomAccessFile" name="OUT-FILE" fileName="${file.name.tmp}${file.suffix}"
filePattern="${file.name.tmp}-%2i${file.suffix}" ignoreExceptions="false">
> 					<Layout Type="PatternLayout" Pattern="${pattern.single}" />
> 					<Policies>
> 						<SizeBasedTriggeringPolicy size="${sizeBasedTriggeringPolicy.size}" />
> 					</Policies>
> 					<DefaultRolloverStrategy max="${defaultRolloverStrategy.max}" fileIndex="min"
/>
> 				</Appender>
> 			</Failovers>
> 		</Appender>
> 		<Async name="ASYNC-OUT-FAIL">
> 			<AppenderRef ref="OUT-FAIL" />
> 		</Async>
> 	</Appenders>
> 	<Loggers>
> 		<asyncRoot level="all">
> 			<AppenderRef ref="ASYNC-OUT-FAIL" />
> 		</asyncRoot>
> 		<asyncLogger name="com" level="error" />
> 		<asyncLogger name="org" level="error" />
> 		<asyncLogger name="javax" level="error" />
> 	</Loggers>
> </Configuration>
> {code}
> h1. Test
> h2. Code
> {code}
> public abstract class LogTest {
>     public static void main(String... args) throws Exception {
>         Logger logger = LogManager.getLogger();
>         for (int i = 0; i < Integer.MAX_VALUE; i++) {
>             logger.info(i);
>         }
>         System.exit(0);
>     }
> }
> {code}
> h2. Result
> The client and server are started as different applications and uses seperate jvm. If
the client terminates with system.exit everything is fine. But if the client is Terminiated
by TaskKill or the jvm crashes. The server outputs multiple times the following trace.
> {code}
> 2015-11-18 11:26:33,479 Thread-9 ERROR  java.net.SocketException: Connection reset
> 	at java.net.SocketInputStream.read(SocketInputStream.java:154)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:141)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:127)
> 	at org.apache.logging.log4j.core.net.server.InputStreamLogEventBridge.logEvents(InputStreamLogEventBridge.java:62)
> 	at org.apache.logging.log4j.core.net.server.TcpSocketServer$SocketHandler.run(TcpSocketServer.java:62)
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message