Re: log4j2 2.0-rc1 issues on AIX
+1 to the default of Block! 1ns is too small. No wonder is sucked CPU. :-) Thanks for looking! -Chris Sent from my iPhone On 21/03/2014, at 1:32 PM, Remko Popma wrote: > Took another look at the Disruptor SleepingWait strategy. It actually uses > a back-off strategy. From the javadoc: > > Sleeping strategy that initially spins, then uses a Thread.yield(), and > eventually for the minimum number of nanos the OS and JVM will allow while > the {@link com.lmax.disruptor.EventProcessor}s are waiting on a barrier. > This strategy is a good compromise between performance and CPU resource. > Latency spikes can occur after quiet periods. > > The Disruptor SleepingWait strategy code eventually calls LockSupport. > parkNanos(1L); > Different platforms have different timer resolution (I think Windows cannot > go smaller than ~15 millis), and it is possible that AIX has a more > accurate clock. > > I'm beginning to think perhaps BlockingWait should be the default for log4j. > > On Fri, Mar 21, 2014 at 9:33 AM, Chris Graham wrote: > >> The AIX system clock is not the same base time as most Intel boxes. What is >> the sleep time in the sleep strategy? If it's being derived, it might be >> too small. ??? >> >> Just a thought. >> >> To further complicate matters, this particular lpar was uncapped, which >> means that it can steal CPU from other lpars that are not as busy. So the >> number of active CPU's can dynamically vary. >> >> -Chris >> >> >> >> On Fri, Mar 21, 2014 at 9:01 AM, Remko Popma >> wrote: >> >>> No, it turned out that the docs for Apache Archiva were incorrect and the >>> WaitStrategy was effectively still SleepingWaitStrategy. Using the >> correct >>> config to specify BlockingWaitStrategy solved the issue. (LOG4J2-571) >>> >>> FYI, the wait strategy determines what the consumer thread does when the >>> queue is empty & it's waiting for events. Some specialized apps want to >>> avoid the latency of waking up a blocked thread, so there are a number of >>> options with different trade-offs, with busy spin on one end of the >>> spectrum and blocking on the other. For log4j I reduced the set of >>> available options (no busy spin), and choose SleepingWait as the >> default. >>> This had the best performance in my testing. Until now I hadn't seen any >>> excessive CPU usage. >>> >>> Sent from my iPhone >>> On 2014/03/20, at 22:10, Matt Sicker wrote: Perhaps lmax disruptor doesn't work properly in the IBM JVM? > On Tuesday, 18 March 2014, Chris Graham wrote: > > JStack is a Sun thing. This is the IBM JDK on AIX. > I've run the tprof command twice and verified it. > > The full work though follows. > > The output from topas (same as top, effectively) is: > > Topas Monitor for host:XXX EVENTS/QUEUES >>> FILE/TTY > Wed Mar 19 14:49:55 2014 Interval: 2 Cswitch3581 > Readch 686 > Syscall2763 >> Writech > 1378 > CPU User% Kern% Wait% Idle% Physc Entc Reads 7 > Rawin 0 > ALL 48.81.20.0 50.1 1.03 51.7 Writes5 > Ttyout 643 > Forks 0 > Igets 0 > Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 > Namei81 > Total 2.8 10.0 7.5 1.1 1.7 Runqueue1.0 > Dirblk0 > Waitqueue 0.0 > DiskBusy% KBPS TPS KB-Read KB-Writ >> MEMORY > Total 0.0 0.0 0.0 0.0 0.0 PAGING >> Real,MB > 20480 > Faults3 % Comp > 44 > FileSystemKBPS TPS KB-Read KB-Writ Steals0 % >>> Noncomp > 54 > Total 0.6 1.50.60.0PgspIn0 % >>> Client > 54 > PgspOut 0 > NamePID CPU% PgSp Owner PageIn0 >> PAGING > SPACE > java9437312 48.6 739.1 wasadminPageOut 0 >> Size,MB > 15552 > > Process with a PID of 9437312 is the WebSphere instance that runs >>> Archiva, > the problem in question. > > We then use a native AIX tool, tprof to examine that process, and see >>> what > it's doing: > > tprof -j -P 9437312 -skex sleep 60 > > This generates sleep.prof, and the relevant section is: > > Configuration information > = > System: AIX 6.1 Node: au02qap207teax2 Machine: 00C43D204C00 > Tprof command was: > tprof -j -P 9437312 -skex sleep 60 > Trace command was: > /usr/bin/trace -ad -M -L 2438933299 -T 50 -j > 00A,001,002,003,38F,005,006,134,210,139,5A2,5A5,465,234,5D8, -o - > Total Samples = 24008 > Traced Ti
Re: Race Condition for ${web:contextPath} ?
Are you using 2.0-rc1? I fixed a bug that might be the same problem. Ralph > On Mar 20, 2014, at 6:01 PM, "Casazza, Robert" > wrote: > > > Hi, > > I'm having problems narrowing it down, but there seems to be a race condition > of some sort while using ${web: > > More often than not, it appears that the LoggerContext lc > getExternalContext() is null in the WebLookup getServletContext() method. > > Running on tomcat 7.0.52, decided to initialize log4j2 in the web.xml while > debugging. I haven't narrowed down the cause nor a workaround. > > Strangely, every so often the Lookup resolves correctly. > > Is there a workaround? Have you seen this behavior? > > Thanks, > Bob > > > > > CONFIDENTIALITY NOTICE > This transmission is intended for the sole use of the individual and/or > entity to whom it is addressed, and may contain information and/or > attachments that are privileged, confidential and exempt from disclosure > under applicable law. If the reader of this transmission is not the intended > recipient, you are hereby notified that any disclosure, dissemination, > distribution, duplication or the taking of any action in reliance on the > contents of this transmission by someone other than the intended addressee or > its designated agent is strictly prohibited. If your receipt of this > transmission is in error, please notify the sender by replying immediately to > this transmission and destroying the transmission. For your protection, do > not include Social Security numbers, passwords or other non-public and > personal information in your email. Thank you. - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org
Re: log4j2 2.0-rc1 issues on AIX
Took another look at the Disruptor SleepingWait strategy. It actually uses a back-off strategy. From the javadoc: Sleeping strategy that initially spins, then uses a Thread.yield(), and eventually for the minimum number of nanos the OS and JVM will allow while the {@link com.lmax.disruptor.EventProcessor}s are waiting on a barrier. This strategy is a good compromise between performance and CPU resource. Latency spikes can occur after quiet periods. The Disruptor SleepingWait strategy code eventually calls LockSupport. parkNanos(1L); Different platforms have different timer resolution (I think Windows cannot go smaller than ~15 millis), and it is possible that AIX has a more accurate clock. I'm beginning to think perhaps BlockingWait should be the default for log4j. On Fri, Mar 21, 2014 at 9:33 AM, Chris Graham wrote: > The AIX system clock is not the same base time as most Intel boxes. What is > the sleep time in the sleep strategy? If it's being derived, it might be > too small. ??? > > Just a thought. > > To further complicate matters, this particular lpar was uncapped, which > means that it can steal CPU from other lpars that are not as busy. So the > number of active CPU's can dynamically vary. > > -Chris > > > > On Fri, Mar 21, 2014 at 9:01 AM, Remko Popma > wrote: > > > No, it turned out that the docs for Apache Archiva were incorrect and the > > WaitStrategy was effectively still SleepingWaitStrategy. Using the > correct > > config to specify BlockingWaitStrategy solved the issue. (LOG4J2-571) > > > > FYI, the wait strategy determines what the consumer thread does when the > > queue is empty & it's waiting for events. Some specialized apps want to > > avoid the latency of waking up a blocked thread, so there are a number of > > options with different trade-offs, with busy spin on one end of the > > spectrum and blocking on the other. For log4j I reduced the set of > > available options (no busy spin), and choose SleepingWait as the > default. > > This had the best performance in my testing. Until now I hadn't seen any > > excessive CPU usage. > > > > Sent from my iPhone > > > > > On 2014/03/20, at 22:10, Matt Sicker wrote: > > > > > > Perhaps lmax disruptor doesn't work properly in the IBM JVM? > > > > > >> On Tuesday, 18 March 2014, Chris Graham wrote: > > >> > > >> JStack is a Sun thing. This is the IBM JDK on AIX. > > >> I've run the tprof command twice and verified it. > > >> > > >> The full work though follows. > > >> > > >> The output from topas (same as top, effectively) is: > > >> > > >> Topas Monitor for host:XXX EVENTS/QUEUES > > FILE/TTY > > >> Wed Mar 19 14:49:55 2014 Interval: 2 Cswitch3581 > > >> Readch 686 > > >>Syscall2763 > Writech > > >> 1378 > > >> CPU User% Kern% Wait% Idle% Physc Entc Reads 7 > > >> Rawin 0 > > >> ALL 48.81.20.0 50.1 1.03 51.7 Writes5 > > >> Ttyout 643 > > >>Forks 0 > > >> Igets 0 > > >> Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 > > >> Namei81 > > >> Total 2.8 10.0 7.5 1.1 1.7 Runqueue1.0 > > >> Dirblk0 > > >>Waitqueue 0.0 > > >> DiskBusy% KBPS TPS KB-Read KB-Writ > MEMORY > > >> Total 0.0 0.0 0.0 0.0 0.0 PAGING > Real,MB > > >> 20480 > > >>Faults3 % Comp > > >> 44 > > >> FileSystemKBPS TPS KB-Read KB-Writ Steals0 % > > Noncomp > > >> 54 > > >> Total 0.6 1.50.60.0PgspIn0 % > > Client > > >> 54 > > >>PgspOut 0 > > >> NamePID CPU% PgSp Owner PageIn0 > PAGING > > >> SPACE > > >> java9437312 48.6 739.1 wasadminPageOut 0 > Size,MB > > >> 15552 > > >> > > >> Process with a PID of 9437312 is the WebSphere instance that runs > > Archiva, > > >> the problem in question. > > >> > > >> We then use a native AIX tool, tprof to examine that process, and see > > what > > >> it's doing: > > >> > > >> tprof -j -P 9437312 -skex sleep 60 > > >> > > >> This generates sleep.prof, and the relevant section is: > > >> > > >> Configuration information > > >> = > > >> System: AIX 6.1 Node: au02qap207teax2 Machine: 00C43D204C00 > > >> Tprof command was: > > >>tprof -j -P 9437312 -skex sleep 60 > > >> Trace command was: > > >>/usr/bin/trace -ad -M -L 2438933299 -T 50 -j > > >> 00A,001,002,003,38F,005,006,134,210,139,5A2,5A5,465,234,5D8, -o - > > >> Total Samples = 24008 > > >> Traced Time = 60.02s (out of a total execution time of 60.02s) > > >> > > >> > > > > > >> > > >> Process
Race Condition for ${web:contextPath} ?
Hi, I'm having problems narrowing it down, but there seems to be a race condition of some sort while using ${web: More often than not, it appears that the LoggerContext lc getExternalContext() is null in the WebLookup getServletContext() method. Running on tomcat 7.0.52, decided to initialize log4j2 in the web.xml while debugging. I haven't narrowed down the cause nor a workaround. Strangely, every so often the Lookup resolves correctly. Is there a workaround? Have you seen this behavior? Thanks, Bob CONFIDENTIALITY NOTICE This transmission is intended for the sole use of the individual and/or entity to whom it is addressed, and may contain information and/or attachments that are privileged, confidential and exempt from disclosure under applicable law. If the reader of this transmission is not the intended recipient, you are hereby notified that any disclosure, dissemination, distribution, duplication or the taking of any action in reliance on the contents of this transmission by someone other than the intended addressee or its designated agent is strictly prohibited. If your receipt of this transmission is in error, please notify the sender by replying immediately to this transmission and destroying the transmission. For your protection, do not include Social Security numbers, passwords or other non-public and personal information in your email. Thank you.
Re: log4j2 2.0-rc1 issues on AIX
The AIX system clock is not the same base time as most Intel boxes. What is the sleep time in the sleep strategy? If it's being derived, it might be too small. ??? Just a thought. To further complicate matters, this particular lpar was uncapped, which means that it can steal CPU from other lpars that are not as busy. So the number of active CPU's can dynamically vary. -Chris On Fri, Mar 21, 2014 at 9:01 AM, Remko Popma wrote: > No, it turned out that the docs for Apache Archiva were incorrect and the > WaitStrategy was effectively still SleepingWaitStrategy. Using the correct > config to specify BlockingWaitStrategy solved the issue. (LOG4J2-571) > > FYI, the wait strategy determines what the consumer thread does when the > queue is empty & it's waiting for events. Some specialized apps want to > avoid the latency of waking up a blocked thread, so there are a number of > options with different trade-offs, with busy spin on one end of the > spectrum and blocking on the other. For log4j I reduced the set of > available options (no busy spin), and choose SleepingWait as the default. > This had the best performance in my testing. Until now I hadn't seen any > excessive CPU usage. > > Sent from my iPhone > > > On 2014/03/20, at 22:10, Matt Sicker wrote: > > > > Perhaps lmax disruptor doesn't work properly in the IBM JVM? > > > >> On Tuesday, 18 March 2014, Chris Graham wrote: > >> > >> JStack is a Sun thing. This is the IBM JDK on AIX. > >> I've run the tprof command twice and verified it. > >> > >> The full work though follows. > >> > >> The output from topas (same as top, effectively) is: > >> > >> Topas Monitor for host:XXX EVENTS/QUEUES > FILE/TTY > >> Wed Mar 19 14:49:55 2014 Interval: 2 Cswitch3581 > >> Readch 686 > >>Syscall2763 Writech > >> 1378 > >> CPU User% Kern% Wait% Idle% Physc Entc Reads 7 > >> Rawin 0 > >> ALL 48.81.20.0 50.1 1.03 51.7 Writes5 > >> Ttyout 643 > >>Forks 0 > >> Igets 0 > >> Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 > >> Namei81 > >> Total 2.8 10.0 7.5 1.1 1.7 Runqueue1.0 > >> Dirblk0 > >>Waitqueue 0.0 > >> DiskBusy% KBPS TPS KB-Read KB-Writ MEMORY > >> Total 0.0 0.0 0.0 0.0 0.0 PAGING Real,MB > >> 20480 > >>Faults3 % Comp > >> 44 > >> FileSystemKBPS TPS KB-Read KB-Writ Steals0 % > Noncomp > >> 54 > >> Total 0.6 1.50.60.0PgspIn0 % > Client > >> 54 > >>PgspOut 0 > >> NamePID CPU% PgSp Owner PageIn0 PAGING > >> SPACE > >> java9437312 48.6 739.1 wasadminPageOut 0 Size,MB > >> 15552 > >> > >> Process with a PID of 9437312 is the WebSphere instance that runs > Archiva, > >> the problem in question. > >> > >> We then use a native AIX tool, tprof to examine that process, and see > what > >> it's doing: > >> > >> tprof -j -P 9437312 -skex sleep 60 > >> > >> This generates sleep.prof, and the relevant section is: > >> > >> Configuration information > >> = > >> System: AIX 6.1 Node: au02qap207teax2 Machine: 00C43D204C00 > >> Tprof command was: > >>tprof -j -P 9437312 -skex sleep 60 > >> Trace command was: > >>/usr/bin/trace -ad -M -L 2438933299 -T 50 -j > >> 00A,001,002,003,38F,005,006,134,210,139,5A2,5A5,465,234,5D8, -o - > >> Total Samples = 24008 > >> Traced Time = 60.02s (out of a total execution time of 60.02s) > >> > >> > > >> > >> Process Freq Total Kernel User Shared Other > >> Java > >> === = == == = > >> > >> wait4 64.29 64.29 0.00 0.00 0.00 > >> 0.00 > >> java 182 34.66 1.97 0.00 32.65 0.05 > >> 0.00 > >> /usr/sbin/syncd 2 0.17 0.17 0.00 0.00 0.00 > >> 0.00 > >> sshd: 1 0.14 0.09 0.05 0.01 0.00 > >> 0.00 > >> /usr/bin/ps13 0.12 0.10 0.00 0.03 0.00 > >> 0.00 > >> /usr/bin/sh27 0.12 0.11 0.00 0.00 0.00 > >> 0.00 > >> httpd 12 0.09 0.05 0.01 0.03 0.00 > >> 0.00 > >> /usr/bin/scp1 0.09 0.07 0.00 0.01 0.00 > >> 0.00 > >> /opt/freeware/bin/readlink 6 0.04 0.04 0.00 0.00 0.00 > >> 0.00 > >> /usr/bin/tprof 1 0.03 0.00 0.01 0.02 0.00 >
Re: log4j2 2.0-rc1 issues on AIX
No, it turned out that the docs for Apache Archiva were incorrect and the WaitStrategy was effectively still SleepingWaitStrategy. Using the correct config to specify BlockingWaitStrategy solved the issue. (LOG4J2-571) FYI, the wait strategy determines what the consumer thread does when the queue is empty & it's waiting for events. Some specialized apps want to avoid the latency of waking up a blocked thread, so there are a number of options with different trade-offs, with busy spin on one end of the spectrum and blocking on the other. For log4j I reduced the set of available options (no busy spin), and choose SleepingWait as the default. This had the best performance in my testing. Until now I hadn't seen any excessive CPU usage. Sent from my iPhone > On 2014/03/20, at 22:10, Matt Sicker wrote: > > Perhaps lmax disruptor doesn't work properly in the IBM JVM? > >> On Tuesday, 18 March 2014, Chris Graham wrote: >> >> JStack is a Sun thing. This is the IBM JDK on AIX. >> I've run the tprof command twice and verified it. >> >> The full work though follows. >> >> The output from topas (same as top, effectively) is: >> >> Topas Monitor for host:XXX EVENTS/QUEUESFILE/TTY >> Wed Mar 19 14:49:55 2014 Interval: 2 Cswitch3581 >> Readch 686 >>Syscall2763 Writech >> 1378 >> CPU User% Kern% Wait% Idle% Physc Entc Reads 7 >> Rawin 0 >> ALL 48.81.20.0 50.1 1.03 51.7 Writes5 >> Ttyout 643 >>Forks 0 >> Igets 0 >> Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 >> Namei81 >> Total 2.8 10.0 7.5 1.1 1.7 Runqueue1.0 >> Dirblk0 >>Waitqueue 0.0 >> DiskBusy% KBPS TPS KB-Read KB-Writ MEMORY >> Total 0.0 0.0 0.0 0.0 0.0 PAGING Real,MB >> 20480 >>Faults3 % Comp >> 44 >> FileSystemKBPS TPS KB-Read KB-Writ Steals0 % Noncomp >> 54 >> Total 0.6 1.50.60.0PgspIn0 % Client >> 54 >>PgspOut 0 >> NamePID CPU% PgSp Owner PageIn0 PAGING >> SPACE >> java9437312 48.6 739.1 wasadminPageOut 0 Size,MB >> 15552 >> >> Process with a PID of 9437312 is the WebSphere instance that runs Archiva, >> the problem in question. >> >> We then use a native AIX tool, tprof to examine that process, and see what >> it's doing: >> >> tprof -j -P 9437312 -skex sleep 60 >> >> This generates sleep.prof, and the relevant section is: >> >> Configuration information >> = >> System: AIX 6.1 Node: au02qap207teax2 Machine: 00C43D204C00 >> Tprof command was: >>tprof -j -P 9437312 -skex sleep 60 >> Trace command was: >>/usr/bin/trace -ad -M -L 2438933299 -T 50 -j >> 00A,001,002,003,38F,005,006,134,210,139,5A2,5A5,465,234,5D8, -o - >> Total Samples = 24008 >> Traced Time = 60.02s (out of a total execution time of 60.02s) >> >> >> >> Process Freq Total Kernel User Shared Other >> Java >> === = == == = >> >> wait4 64.29 64.29 0.00 0.00 0.00 >> 0.00 >> java 182 34.66 1.97 0.00 32.65 0.05 >> 0.00 >> /usr/sbin/syncd 2 0.17 0.17 0.00 0.00 0.00 >> 0.00 >> sshd: 1 0.14 0.09 0.05 0.01 0.00 >> 0.00 >> /usr/bin/ps13 0.12 0.10 0.00 0.03 0.00 >> 0.00 >> /usr/bin/sh27 0.12 0.11 0.00 0.00 0.00 >> 0.00 >> httpd 12 0.09 0.05 0.01 0.03 0.00 >> 0.00 >> /usr/bin/scp1 0.09 0.07 0.00 0.01 0.00 >> 0.00 >> /opt/freeware/bin/readlink 6 0.04 0.04 0.00 0.00 0.00 >> 0.00 >> /usr/bin/tprof 1 0.03 0.00 0.01 0.02 0.00 >> 0.00 >> kulagent7 0.03 0.02 0.00 0.00 0.00 >> 0.00 >> swapper 1 0.02 0.02 0.00 0.00 0.00 >> 0.00 >> /usr/bin/grep 5 0.02 0.02 0.00 0.00 0.00 >> 0.00 >> /usr/sbin/getty 1 0.02 0.02 0.00 0.00 0.00 >> 0.00 >> kuxagent3 0.02 0.01 0.00 0.00 0.00 >> 0.00 >> lrud1 0.02 0.02 0.00 0.00 0.00 >> 0.00 >> srmAIX 3 0.01 0.01 0.00 0.00 0.00 >> 0.00 >> /opt/tivoli/cit/bin/wscanuse
log4.properties not honoring properties
Greetings to the list: We have a log4j v.1.2.14 on my CentOS 6.4 host with tomcat v6.0.24 Our Application Servlet is version 2.5 and we did not develop this application. our classes directory has a single log4j.properties with this content: log4j.rootLogger=DEBUG, R log4j.appender.R = org.apache.log4j.DailyRollingFileAppender log4j.appender.R.File = logs/FileServer.log log4j.appender.R.Append = true log4j.appender.R.DatePattern = '.'yyy-MM-dd log4j.appender.R.layout = org.apache.log4j.PatternLayout log4j.appender.R.layout.ConversionPattern = %d{-MM-dd HH:mm:ss} %c{1} [%p] %m%n My concern is that the FileServer.log file is being written to /var/log/tomcat6 and not /logs Following the direction at http://tomcat.apache.org/tomcat-6.0-doc/logging.html#Using_Log4j specifically, the /Note: /that says "These steps are *not* needed if you just want to use log4j in your own web application. --- In that case, just put |log4j.jar| and |log4j.properties| into |WEB-INF/lib| and |WEB-INF/classes| of your web application. which I have done and bounced the tomcat6 service. What I notice are these things: There is a /etc/tomcat6/log4j.properties as well. the FileServer.log files shows "log5jImp" ? 2014-03-20 12:07:21 *Log5jImp* [DEBUG] Starting FileServer Restlet Listener Sure could use a hand in getting the FileServer.log file logging to /logs/FileServer.log Thank you for your valuable time. Have a Great Day! -- John Jones cirrhus9.com
Re: beta9 to rc1
It is hard to answer your question just based on this email. First, if you are getting an exception when starting Tomcat please open a Jira issue and attach the log with the exception in it. Is the stack trace below the exception? Second, if lookups aren’t working we need a better description of what is not working. I’m not sure why you have “$${web:contextPath}” and “$${sys:catalina.home}” in your configuration below though. Those should be resolved when the configuration is processed. Ralph On Mar 19, 2014, at 7:07 PM, Mahesh Dilhan wrote: > HI > > I'm using AsyncLogger and it satisfied the what i need. > 1 : Asysnc logger [tomcat is configured with the property > {Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector > } > > 2. I'm using rolling random access appender > > 3. *Lookups *works as expected > > > > Following is a part of log4j2.xml. > > > > >$${web:contextPath} > $${sys:catalina.home} > name="filename">${catalinaHome}/logs/current/${contextName}.log > > > > fileName="${filename}" immediateFlush="false" append="false" > > filePattern="${catalinaHome}/logs/archived/%d{-MM-dd}${contextName}-%d{-MM-dd}.log.gz"> > >%d %p %c{1.} [%t] %m%n > > > > > > > > > > Everything was perfect before I change the version from *beta9 *to *rc1* > > 1. Exception occurred while initializing tomcat, *but this is not a show > stopper*. > 2. File is created with a name AsyncLoggerContext.log. > 3. *Lookup suddenly stop working , which is a show stopper for me* > > > > So I had to rollback the version again. > > are there any new configuration which comes with *rc1?* > > > SEVERE: IOException while loading persisted sessions: > java.io.WriteAbortedException: writing aborted; > java.io.NotSerializableException: org.ap > ache.logging.log4j.core.Logger$PrivateConfig > java.io.WriteAbortedException: writing aborted; > java.io.NotSerializableException: > org.apache.logging.log4j.core.Logger$PrivateConfig >at > java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1333) >at > java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947) >at > java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871) >at > java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753) >at > java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329) >at > java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947) >at > java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871) >at > java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753) >at > java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329) >at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351) >at java.util.HashMap.readObject(HashMap.java:1030) >at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) >at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >at java.lang.reflect.Method.invoke(Method.java:597) >at > java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:974) >at > java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1849) >at > java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753) >at > java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329) >at > java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947) >at > java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871) >at > java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753) >at > java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329) >at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351) >at > org.apache.catalina.session.StandardSession.readObject(StandardSession.java:1597) >at > org.apache.catalina.session.StandardSession.readObjectData(StandardSession.java:1062) >at > org.apache.catalina.session.StandardManager.doLoad(StandardManager.java:284) >at > org.apache.catalina.session.StandardManager.load(StandardManager.java:204) >at > org.apache.catalina.session.StandardManager.startInternal(StandardManager.java:491) >at > org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) >at > org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5443) >at > org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) >at > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901) >at > org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877) >at > org.apache.catalina.core.Standa
Re: log4j2 2.0-rc1 issues on AIX
Perhaps lmax disruptor doesn't work properly in the IBM JVM? On Tuesday, 18 March 2014, Chris Graham wrote: > JStack is a Sun thing. This is the IBM JDK on AIX. > I've run the tprof command twice and verified it. > > The full work though follows. > > The output from topas (same as top, effectively) is: > > Topas Monitor for host:XXX EVENTS/QUEUESFILE/TTY > Wed Mar 19 14:49:55 2014 Interval: 2 Cswitch3581 > Readch 686 > Syscall2763 Writech > 1378 > CPU User% Kern% Wait% Idle% Physc Entc Reads 7 > Rawin 0 > ALL 48.81.20.0 50.1 1.03 51.7 Writes5 > Ttyout 643 > Forks 0 > Igets 0 > Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 > Namei81 > Total 2.8 10.0 7.5 1.1 1.7 Runqueue1.0 > Dirblk0 > Waitqueue 0.0 > DiskBusy% KBPS TPS KB-Read KB-Writ MEMORY > Total 0.0 0.0 0.0 0.0 0.0 PAGING Real,MB > 20480 > Faults3 % Comp > 44 > FileSystemKBPS TPS KB-Read KB-Writ Steals0 % Noncomp > 54 > Total 0.6 1.50.60.0PgspIn0 % Client > 54 > PgspOut 0 > NamePID CPU% PgSp Owner PageIn0 PAGING > SPACE > java9437312 48.6 739.1 wasadminPageOut 0 Size,MB > 15552 > > Process with a PID of 9437312 is the WebSphere instance that runs Archiva, > the problem in question. > > We then use a native AIX tool, tprof to examine that process, and see what > it's doing: > > tprof -j -P 9437312 -skex sleep 60 > > This generates sleep.prof, and the relevant section is: > > Configuration information > = > System: AIX 6.1 Node: au02qap207teax2 Machine: 00C43D204C00 > Tprof command was: > tprof -j -P 9437312 -skex sleep 60 > Trace command was: > /usr/bin/trace -ad -M -L 2438933299 -T 50 -j > 00A,001,002,003,38F,005,006,134,210,139,5A2,5A5,465,234,5D8, -o - > Total Samples = 24008 > Traced Time = 60.02s (out of a total execution time of 60.02s) > > > > Process Freq Total Kernel User Shared Other > Java > === = == == = > > wait4 64.29 64.29 0.00 0.00 0.00 > 0.00 > java 182 34.66 1.97 0.00 32.65 0.05 > 0.00 > /usr/sbin/syncd 2 0.17 0.17 0.00 0.00 0.00 > 0.00 > sshd: 1 0.14 0.09 0.05 0.01 0.00 > 0.00 > /usr/bin/ps13 0.12 0.10 0.00 0.03 0.00 > 0.00 > /usr/bin/sh27 0.12 0.11 0.00 0.00 0.00 > 0.00 > httpd 12 0.09 0.05 0.01 0.03 0.00 > 0.00 > /usr/bin/scp1 0.09 0.07 0.00 0.01 0.00 > 0.00 > /opt/freeware/bin/readlink 6 0.04 0.04 0.00 0.00 0.00 > 0.00 > /usr/bin/tprof 1 0.03 0.00 0.01 0.02 0.00 > 0.00 > kulagent7 0.03 0.02 0.00 0.00 0.00 > 0.00 > swapper 1 0.02 0.02 0.00 0.00 0.00 > 0.00 > /usr/bin/grep 5 0.02 0.02 0.00 0.00 0.00 > 0.00 > /usr/sbin/getty 1 0.02 0.02 0.00 0.00 0.00 > 0.00 > kuxagent3 0.02 0.01 0.00 0.00 0.00 > 0.00 > lrud1 0.02 0.02 0.00 0.00 0.00 > 0.00 > srmAIX 3 0.01 0.01 0.00 0.00 0.00 > 0.00 > /opt/tivoli/cit/bin/wscanuse1 0.01 0.01 0.00 0.00 0.00 > 0.00 > psmd1 0.01 0.01 0.00 0.00 0.00 > 0.00 > xmgc1 0.01 0.01 0.00 0.00 0.00 > 0.00 > nfs_stat2 0.01 0.01 0.00 0.00 0.00 > 0.00 > /usr/bin/topasrec 2 0.01 0.01 0.00 0.00 0.00 > 0.00 > /usr/bin/xmtopas1 0.01 0.00 0.00 0.00 0.00 > 0.00 > kcawd 1 0.00 0.00 0.00 0.00 0.00 > 0.00 > /usr/sbin/snmpd 1 0.00 0.00 0.00 0.00 0.00 > 0.00 > /usr/sbin/snmpmibd 1 0.00 0.00 0.00 0.00 0.00 > 0.00 > /usr/bin/date 1 0.00 0.00 0.00 0.00 0.00 > 0.00 > /usr/bin/entstat1 0.00 0.00 0.00 0.00 0.00 > 0.00 > gil 1 0.00 0.00 0.00 0.00 0.