100% CPU in infinite loop : JDK was guilty!
taccart.thierry.accart.name Apr 17, 2009 9:22 AMHi readers
Just an experience I wanted to share : the guilty guy is not always the one you're told :-)
We've been told that our seam application was causing 100% CPU usage (never ending).
Context : JBoss 4.2.2, JDK 1.5.0_03, Seam 2.0.1 GA
After loosing a bit time trying reproduce, we did a monkey test (press F5 for 5 seconds) on the home page of our webapp and ... bingo ! cpu locked at 100% !
Okay : our application can cause an infinite loop...
After deeper investigation on the root cause of this infinite loop, we found that it was the JVM !! (http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6241823)
Thanks to open source concept : we could investigate on the jvm source code, we found the bug, identified the root cause, and fixed the problem (by updating our JDK).
Rgds
For those who want to see stacktrace of infinite loop :
ReentrantLock$FairSync(AbstractQueuedSynchronizer).fullGetFirstQueuedThread()
line: 1246 [local variables unavailable]
ReentrantLock$FairSync(AbstractQueuedSynchronizer).getFirstQueuedThread() line:
1233
ReentrantLock$FairSync.tryAcquire(int) line: 208
ReentrantLock$FairSync(AbstractQueuedSynchronizer).tryAcquireNanos(int, long)
line: 1087
ReentrantLock.tryLock(long, TimeUnit) line: 416
ConversationEntry.lock() line: 204
FacesManager(Manager).restoreAndLockConversation(ConversationEntry) line: 490
FacesManager(Manager).restoreConversation() line: 485
SeamPhaseListener.afterRestoreView(FacesContext) line: 377
SeamPhaseListener.afterServletPhase(PhaseEvent) line: 216
SeamPhaseListener.afterPhase(PhaseEvent) line: 182
LifecycleImpl.phase(PhaseId, Phase, FacesContext) line: 280
LifecycleImpl.execute(FacesContext) line: 117
FacesServlet.service(ServletRequest, ServletResponse) line: 244
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
290
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 83
MultipartFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 85
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
ExceptionFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 64
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
RedirectFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 45
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
ConfigurableXMLFilter(BaseXMLFilter).doXmlFilter(FilterChain,
HttpServletRequest, HttpServletResponse) line: 154
Filter(BaseFilter).handleRequest(HttpServletRequest, HttpServletResponse,
FilterChain) line: 260
Filter(BaseFilter).processUploadsAndHandleRequest(HttpServletRequest,
HttpServletResponse, FilterChain) line: 366
Filter(BaseFilter).doFilter(ServletRequest, ServletResponse, FilterChain) line:
493
Ajax4jsfFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 60
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
LoggingFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 58
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
SeamFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 158
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
235
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
ReplyHeaderFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line:
96
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
235
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
StandardWrapperValve.invoke(Request, Response) line: 230
StandardContextValve.invoke(Request, Response) line: 175
SecurityAssociationValve.invoke(Request, Response) line: 179
BasicAuthenticator(AuthenticatorBase).invoke(Request, Response) line: 432
JaccContextValve.invoke(Request, Response) line: 84
StandardHostValve.invoke(Request, Response) line: 127
ErrorReportValve.invoke(Request, Response) line: 102
CachedConnectionValve.invoke(Request, Response) line: 157
AccessLogValve.invoke(Request, Response) line: 562
StandardEngineValve.invoke(Request, Response) line: 109
CoyoteAdapter.service(Request, Response) line: 262
Http11Processor.process(Socket) line: 844
Http11Protocol$Http11ConnectionHandler.process(Socket) line: 583
JIoEndpoint$Worker.run() line: 446
Thread.run() line: 595
Faulty code from jvm:
It's in jdk :
package java.util.concurrent.locks;
/**
* Version of getFirstQueuedThread called when fastpath fails
*/
private Thread fullGetFirstQueuedThread() {
/*
* This loops only if the queue changes while we read sets of
* fields.
*/
for (;;) {
Node h = head;
if (h == null) // No queue
return null;
/*
* The first node is normally h.next. Try to get its
* thread field, ensuring consistent reads: If thread
* field is nulled out or s.prev is no longer head, then
* some other thread(s) concurrently performed setHead in
* between some of our reads, so we must reread.
*/
Node s = h.next;
if (s != null) {
Thread st = s.thread;
Node sp = s.prev;
if (st != null && sp == head)
return st;
}
/*
* Head's next field might not have been set yet, or may
* have been unset after setHead. So we must check to see
* if tail is actually first node, in almost the same way
* as above.
*/
Node t = tail;
if (t == h) // Empty queue
return null;
if (t != null) {
Thread tt = t.thread;
Node tp = t.prev;
if (tt != null && tp == head)
return tt;
}
}
}
Just an experience I wanted to share : the guilty guy is not always the one you're told :-)
We've been told that our seam application was causing 100% CPU usage (never ending).
Context : JBoss 4.2.2, JDK 1.5.0_03, Seam 2.0.1 GA
After loosing a bit time trying reproduce, we did a monkey test (press F5 for 5 seconds) on the home page of our webapp and ... bingo ! cpu locked at 100% !
Okay : our application can cause an infinite loop...
After deeper investigation on the root cause of this infinite loop, we found that it was the JVM !! (http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6241823)
Thanks to open source concept : we could investigate on the jvm source code, we found the bug, identified the root cause, and fixed the problem (by updating our JDK).
Rgds
For those who want to see stacktrace of infinite loop :
ReentrantLock$FairSync(AbstractQueuedSynchronizer).fullGetFirstQueuedThread()
line: 1246 [local variables unavailable]
ReentrantLock$FairSync(AbstractQueuedSynchronizer).getFirstQueuedThread() line:
1233
ReentrantLock$FairSync.tryAcquire(int) line: 208
ReentrantLock$FairSync(AbstractQueuedSynchronizer).tryAcquireNanos(int, long)
line: 1087
ReentrantLock.tryLock(long, TimeUnit) line: 416
ConversationEntry.lock() line: 204
FacesManager(Manager).restoreAndLockConversation(ConversationEntry) line: 490
FacesManager(Manager).restoreConversation() line: 485
SeamPhaseListener.afterRestoreView(FacesContext) line: 377
SeamPhaseListener.afterServletPhase(PhaseEvent) line: 216
SeamPhaseListener.afterPhase(PhaseEvent) line: 182
LifecycleImpl.phase(PhaseId, Phase, FacesContext) line: 280
LifecycleImpl.execute(FacesContext) line: 117
FacesServlet.service(ServletRequest, ServletResponse) line: 244
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
290
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 83
MultipartFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 85
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
ExceptionFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 64
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
RedirectFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 45
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
ConfigurableXMLFilter(BaseXMLFilter).doXmlFilter(FilterChain,
HttpServletRequest, HttpServletResponse) line: 154
Filter(BaseFilter).handleRequest(HttpServletRequest, HttpServletResponse,
FilterChain) line: 260
Filter(BaseFilter).processUploadsAndHandleRequest(HttpServletRequest,
HttpServletResponse, FilterChain) line: 366
Filter(BaseFilter).doFilter(ServletRequest, ServletResponse, FilterChain) line:
493
Ajax4jsfFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 60
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
LoggingFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 58
SeamFilter$FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 69
SeamFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 158
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
235
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
ReplyHeaderFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line:
96
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line:
235
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
StandardWrapperValve.invoke(Request, Response) line: 230
StandardContextValve.invoke(Request, Response) line: 175
SecurityAssociationValve.invoke(Request, Response) line: 179
BasicAuthenticator(AuthenticatorBase).invoke(Request, Response) line: 432
JaccContextValve.invoke(Request, Response) line: 84
StandardHostValve.invoke(Request, Response) line: 127
ErrorReportValve.invoke(Request, Response) line: 102
CachedConnectionValve.invoke(Request, Response) line: 157
AccessLogValve.invoke(Request, Response) line: 562
StandardEngineValve.invoke(Request, Response) line: 109
CoyoteAdapter.service(Request, Response) line: 262
Http11Processor.process(Socket) line: 844
Http11Protocol$Http11ConnectionHandler.process(Socket) line: 583
JIoEndpoint$Worker.run() line: 446
Thread.run() line: 595
Faulty code from jvm:
It's in jdk :
package java.util.concurrent.locks;
/**
* Version of getFirstQueuedThread called when fastpath fails
*/
private Thread fullGetFirstQueuedThread() {
/*
* This loops only if the queue changes while we read sets of
* fields.
*/
for (;;) {
Node h = head;
if (h == null) // No queue
return null;
/*
* The first node is normally h.next. Try to get its
* thread field, ensuring consistent reads: If thread
* field is nulled out or s.prev is no longer head, then
* some other thread(s) concurrently performed setHead in
* between some of our reads, so we must reread.
*/
Node s = h.next;
if (s != null) {
Thread st = s.thread;
Node sp = s.prev;
if (st != null && sp == head)
return st;
}
/*
* Head's next field might not have been set yet, or may
* have been unset after setHead. So we must check to see
* if tail is actually first node, in almost the same way
* as above.
*/
Node t = tail;
if (t == h) // Empty queue
return null;
if (t != null) {
Thread tt = t.thread;
Node tp = t.prev;
if (tt != null && tp == head)
return tt;
}
}
}