Hi! Some minutes ago I solved the problem by myself:
It seems like log4j is NOT completely thread-save. After synchronizing all log / trace methods using a separate object (synchronized(synObject) {....} ) everything is working fine. Maybe the lib is writing the messages to a shared thread-unsafe buffer which is used by all logger instances before writing them to file?!? (That would explain why sometimes log messages appear inside the trace file) 2009/8/31 Bender Heri <hben...@ergonomics.ch> > Maybe the PatternLayout is not threadsafe? Try to instantiate separate > instances of PatternLayout for each Logger, or synchronize on the sole > instance of PatternLayout. > Heri > PS: It is not quite clear who calls your log method the log-Event, and how > looks the other log method which writes to the traceLogger? > The methods are called by several threads which have access to the loggingHandler class. Inside the handler there are seperated methods for logging (-> logLogger) and tracing (-> traceLogger) a message BTW: Why don't you do the configuring through config file? There is nothing > special in your configuration which cannot be done by config file! > > I think that I don't need a separate config file, because setup is very simple. BR, Markus > > -----Ursprüngliche Nachricht----- > Von: Markus Michel [mailto:nemocadn...@googlemail.com] > Gesendet: Freitag, 28. August 2009 13:58 > An: log4j-user@logging.apache.org > Betreff: Events appear incorrect inside the wrong file > > Hi there! > > To be able to log and trace some events I've added a LoggingHandler class > to my java project. Inside this class I'm using two different log4j logger > instances - one for logging an event and one for tracing an event into > different files. The initialization block of the class looks like this: > > public void initialize() > { > System.out.print("starting logging server ..."); > > // create logger instances > logLogger = Logger.getLogger("log"); > traceLogger = Logger.getLogger("trace"); > > // create pattern layout > String conversionPattern = "%c{2} %d{ABSOLUTE} %r %p %m%n"; > try > { > patternLayout = new PatternLayout(); > patternLayout.setConversionPattern(conversionPattern); > } > catch (Exception e) > { > System.out.println("error: could not create logger layout > pattern"); > System.out.println(e); > System.exit(1); > } > > // add pattern to file appender > try > { > logFileAppender = new FileAppender(patternLayout, logFilename, > false); > traceFileAppender = new FileAppender(patternLayout, > traceFilename, false); > } > catch (IOException e) > { > System.out.println("error: could not add logger layout pattern > to corresponding appender"); > System.out.println(e); > System.exit(1); > } > > // add appenders to loggers > logLogger.addAppender(logFileAppender); > traceLogger.addAppender(traceFileAppender); > > // set logger level > logLogger.setLevel(Level.INFO); > traceLogger.setLevel(Level.INFO); > > // start logging server > loggingServer = new LoggingServer(logLogger, traceLogger, > serverPort, this); > loggingServer.start(); > > System.out.println(" done"); > } > > To make sure that only only thread is using the functionality of a logger > instance at the same time each logging / tracing method calls the logging > method .info() inside a synchronized-block. One example looks like this: > > public void logMessage(String message) > { > synchronized (logFileAppender) > { > if (logLogger.isInfoEnabled() && logFileAppender != null) > { > logLogger.info(instanceName + ": " + message); > } > } > } > > If I look at the log files, I see that sometimes a event appears in the > wrong file. One example: > > trace 10:41:30,773 11080 INFO masterControl(192.168.2.21): string > broadcast message was pushed from 1267093 to vehicle 1055293 (slaveControl > 1) > trace 10:41:30,784 11091 INFO masterControl(192.168.2.21): string > broadcast message was pushed from 1156513 to vehicle 1105792 (slaveControl > 1) > trace 10:41:30,796 11103 INFO masterControl(192.168.2.21): string > broadcast message was pushed from 1104306 to vehicle 1055293 (slaveControl > 1) > trace 10:41:30,808 11115 INFO masterControl(192.168.2.21): vehicle > 1327879 was pushed to slave control 1 > 10:41:30,808 11115 INFO masterControl(192.168.2.21): string broadcast > message was pushed from 1101572 to vehicle 106741 (slaveControl 1) > trace 10:41:30,820 11127 INFO masterControl(192.168.2.21): string > broadcast message was pushed from 1055293 to vehicle 1104306 (slaveControl > 1) > > I think that the problem occures everytime two event happen at the same > time > (here: 10:41:30,808). Does anybody has an idea how to solve my problem? I > already tried to add a sleep() after the method call, but that doesn't > helped ... > > BR, > > Markus > > --------------------------------------------------------------------- > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > For additional commands, e-mail: log4j-user-h...@logging.apache.org > >