Hi Luigi, Thanks for the config. This confirms my hypothesis. If you change the config for the named loggers to add attribute additivity="false" then you should no longer see the duplicate entries. Please refer to the docs on additivity for why it works this way.
By the way, your config has a comment (in German, so not 100% sure) that you are not using the "monitorInterval" attribute because you are worried that reconfiguration will result in lost log events. This was a problem in log4j-1.2, but this is no longer an issue in log4j2. I hope that this is useful information. Best regards, Remko On Wednesday, February 19, 2014, Luigi Alice <[email protected]> wrote: > Hi Remko, > > > > the xml configuration is created dynamically: > > > > <?xml version="1.0" encoding="UTF-8"?> > <!-- Attribut "monitorIntervall" nicht verwenden, da Persis intern dynamisch > umkonfiguriert und dies sonst verloren gehen würde! --> > <configuration> <properties> > <property name="filename">persis.log</property> </properties> > <appenders> <Routing name="PERSIS_GLOBAL"> > <Routes pattern="$${ctx:log.uid}-$${ctx:caller}"> > <Route> > <RollingRandomAccessFile > name="Rolling-${ctx:log.uid}-${ctx:caller}" > fileName = > "${ctx:log.dir}/${ctx:caller}/${ctx:log.uid}_${filename}" > filePattern = > "${ctx:log.dir}/${ctx:caller}/${ctx:log.uid}_persis-%d{yyyy-MM-dd}-%3i.log"> > <!--<RegexFilter regex=".*SystemHandler\.fileHandler.*" onMatch="DENY" > onMismatch="NEUTRAL"/>--> > <!-- file/null Seiten herausfiltern --> > <ThreadContextMapFilter onMatch="DENY" onMismatch="NEUTRAL" operator="or"> > <KeyValuePair key="page" value="file/null"/> </ThreadContextMapFilter> > <PatternLayout charset="UTF-8"> > > <pattern>[%d{HH:mm:ss.SSS}|<!--%X{remoteAddr}-->|<!--%X{session}-->|%X{subThread}|%X{page}|%X{includeStack}|%X{taskID}|%X{levelNo}|%X{location}] > # %m%n</pattern> > </PatternLayout> <Policies> > <SizeBasedTriggeringPolicy size="20 MB"/> > </Policies> <DefaultRolloverStrategy max="1000"/> > </RollingRandomAccessFile> </Route> > </Routes> </Routing> > <Console name="PERSIS_STDOUT" target="SYSTEM_OUT"> > <PatternLayout charset="UTF-8"> > > <pattern>[%d{HH:mm:ss.SSS}|%X{remoteAddr}|%X{session}|%X{subThread}|%X{page}|%X{includeStack}|%X{taskID}|%X{levelNo}|%X{location}] > # %m%n</pattern> > </PatternLayout> </Console> </appenders> > <loggers> <root level="ALL"> > <!-- Hier im AppenderRef bitte den globalen Log-Level anpassen! > --> > <!-- Levels: OFF, ERROR, WARN, INFO, DEBUG, ALL --> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> > <!-- Appender PERSIS_STDOUT wird von Engine aktiviert bei > LogRecorder.setLoggingToStdout() --> > <AppenderRef ref="PERSIS_STDOUT" level="OFF" /> > </root> > <logger name="86FBECE50808FBF684422F95AAAE408E.P011Tomcat70002" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="192.168.0.138" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="192.168.0.160" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="192.168.0.150" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="Scheduler" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="658DC3BEDF712A4D173ED74089235AE5.P011Tomcat70002" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="FEF75997582B3043FF49B83E76494E2E.P011Tomcat70002" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="WARN" /> </logger> > <logger name="192.168.0.140" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > <logger name="A5CFB78C823A53D0058EA517E1E722D6.P011Tomcat70002" level="ALL"> > <AppenderRef ref="PERSIS_GLOBAL" level="DEBUG" /> </logger> > </loggers> </configuration> > > > > So, if I change something this configuration is reloaded. > > Maybe there is still running an old configuration while using a new one? > > > > > > Regards > > > > Mr. L. Alice > > Software developer > > > > > > > > *Von:* Remko Popma > [mailto:[email protected]<javascript:_e(%7B%7D,'cvml','[email protected]');>] > > *Gesendet:* Mittwoch, 19. Februar 2014 12:20 > *An:* Log4J Developers List > *Betreff:* Re: Same log entries multiple times > > > > Hi Luigi, > > > > The first thing that comes to mind is that this may be caused by a log4j > feature called additivity. (Documented here: > http://logging.apache.org/log4j/2.x/manual/configuration.html#Additivity ) > > > > Basically, if your configuration is such that multiple loggers receive a > log event, then each logger will add an identical log file entry unless > Additivity is switched off. > > > > Can you check if this is the case? > > > > Best regards, > > Remko > > Sent from my iPhone > > > On 2014/02/19, at 19:12, Luigi Alice <[email protected]> wrote: > > Hello, > > > > sometimes I have the same log entries multiple times in the log files. > > > > ... > > > [08:55:25.406|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|DBStatementImpl.executeQuery()] # Abgesetzter SQL-Befehl: > [se= lect * from Z_DUMMY] > [08:55:25.406|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|DBStatementImpl.executeQuery()] # Abgesetzter SQL-Befehl: > [se= lect * from Z_DUMMY] > [08:55:25.406|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|DBStatementImpl.executeQuery()] # Abgesetzter SQL-Befehl > abge= schlossen. Execution-time: 0 ms > [08:55:25.406|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|DBStatementImpl.executeQuery()] # Abgesetzter SQL-Befehl > abge= schlossen. Execution-time: 0 ms > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|SelectCommand.executeCommand()] # Select-Kommando: > [selMA.sel= Blub.selBlub]; Anzahl Datens=E4tze: [1]; Execution-time: [0 ms > (sum); 0 ms = (self)]; > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|SelectCommand.executeCommand()] # Select-Kommando: > [selMA.sel= Blub.selBlub]; Anzahl Datens=E4tze: [1]; Execution-time: [0 ms > (sum); 0 ms = (self)]; > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|SelectCommand.executeCommand()] # Select-Kommando: > [selMA.sel= Blub]; Anzahl Datens=E4tze: [1]; Execution-time: [2 ms (sum); 0 > ms (self)]; > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|4|SelectCommand.executeCommand()] # Select-Kommando: > [selMA.sel= Blub]; Anzahl Datens=E4tze: [1]; Execution-time: [2 ms (sum); 0 > ms (self)]; > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|3|CommandSequence.fireSubCommandEvent()] # Logging deaktiviert > = > > ab: selMA.selAtts > > > [08:55:25.407|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|3|CommandSequence.fireSubCommandEvent()] # Logging deaktiviert > = > > ab: selMA.selAtts > > > [08:55:25.409|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|3|CommandSequence.fireSubCommandEvent()] # Logging wieder > aktiv= iert nach: selMA.selAtts > [08:55:25.409|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|3|CommandSequence.fireSubCommandEvent()] # Logging wieder > aktiv= iert nach: selMA.selAtts > [08:55:25.409|0:0:0:0:0:0:0:1|DC4CFAAC6E824F77BA23D01CB2F0D38A||la.test/dyn= > > _table||251|3|CommandSequence. > >
