logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-520) RollingRandomAccessFile with Async Appender skip logs
Date Mon, 05 May 2014 12:34:16 GMT

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

Remko Popma commented on LOG4J2-520:
------------------------------------

I think I got it. It took a bit of debugging, but it turns out that after the shutdown signal
is sent to AsyncAppender.AsyncThread, all events that were still on the queue are not sent
to the underlying appenders.

Here is the relevant code of AsyncAppender:
{code}
public final class AsyncAppender extends AbstractAppender {
    ...
209    private class AsyncThread extends Thread {
        ...
223        public void run() {
            ...
248            // Process any remaining items in the queue.
249            while (!queue.isEmpty()) {
250                try {
251                    final Serializable s = queue.take();
252                    if (s instanceof Log4jLogEvent) { // <----- This is wrong
253                        final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
254                        event.setEndOfBatch(queue.isEmpty());
255                        callAppenders(event);
256                    }
257                } catch (final InterruptedException ex) {
258                    // May have been interrupted to shut down.
259                }
260            }
261        }
{code}

Note that the instanceof check on line 252 means that only elements whose class is {{Log4jLogEvent}}
are processed. It turns out that what is on the queue is objects of class Log4jLogEvent$LogEventProxy.
So the check returns {{false}} and everything that was still on the queue is ignored.

Looks like this check was introduced in revision 1460984. The commit comment says "LOG4J2-146
Avoid IllegalArgumentException in AsynchAppender".

How to fix this? Remove the instanceof check altogether or keep the check but make it work
correctly?
I'm not sure what the instanceof check is trying to protect against, so I'm not sure that
removing it is a good idea.

To keep the check, we can add a method to Log4jLogEvent:
{code}
public static boolean canDeserialize(Serializable s) {
    return s instanceof LogEventProxy;
}
{code}
Note that we cannot change the existing AsyncAppender code to {{if (s instanceof Log4jLogEvent$LogEventProxy)}}
because  Log4jLogEvent$LogEventProxy is a private inner class and is invisible to AsyncAppender.

I think I'll go with the {{canDeserialize}} method.

> RollingRandomAccessFile with Async Appender skip logs
> -----------------------------------------------------
>
>                 Key: LOG4J2-520
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-520
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 2.0-beta9, 2.0-rc1
>         Environment: JDK 1.6, Eclipse
>            Reporter: JavaTech
>            Assignee: Remko Popma
>         Attachments: log4j2.xml
>
>
> I have written a sample code which will write DEBUG, INFO , WARN logs in a single flile,
I have written a logs in FOR loop printing numbers from 1 to 99.
> sometime it print numbers incomplete sequence, like 1 to 67, 1 to 89 etc.
> log4j2.xml
> {code:xml}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration>
>   <Appenders>
>     <RollingRandomAccessFile name="RollingRandomAccessFile"
>       fileName="logs/app.log" filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log"
>       immediateFlush="false" append="true" ignoreExceptions="false">
>       <PatternLayout>
>         <Pattern>%d %-5p [%t] (%F:%L) - %m%n</Pattern>
>       </PatternLayout>
>       <Policies>
>         <TimeBasedTriggeringPolicy />
>         <SizeBasedTriggeringPolicy size="100KB"/>
>       </Policies>
>     </RollingRandomAccessFile>
>     <Async name="ASYNC" includeLocation="true">
>       <AppenderRef ref="RollingRandomAccessFile" />
>     </Async>
>   </Appenders>
>   <Loggers>
>     <Root level="debug" includeLocation="true">
>       <AppenderRef ref="ASYNC" />
>     </Root>
>   </Loggers>
> </Configuration>
> {code}
> Sample Java Code
> {code}
> import org.slf4j.Logger;
> import org.slf4j.LoggerFactory;
> public class LoggerUtil {
> 	public static Logger logger = LoggerFactory.getLogger(LoggerUtil.class);
> 	public static void main(String[] args) {
> 		System.out.println("start");
> 		logger.debug("debug log");
> 		logger.info("info log");
> 		logger.error("error log");
> 		for(int i = 0; i < 99; i++) {
> 			logger.warn("{}",i);
> 			System.out.println("I : - " + i);
> 		}
> 		logger.error("finish printing logs");
> 		System.out.println("end");		
> 	}
> }
> {code}



--
This message was sent by Atlassian JIRA
(v6.2#6252)

---------------------------------------------------------------------
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