Mantis Bugtracker
  

Viewing Issue Simple Details Jump to Notes ] View Advanced ] Issue History ] Print ]
ID Category Severity Reproducibility Date Submitted Last Update
0005599 [Resin] major random 12-03-13 06:25 11-05-14 16:17
Reporter Mathias Lagerwall View Status public  
Assigned To ferg
Priority normal Resolution fixed  
Status closed   Product Version 4.0.36
Summary 0005599: Sometimes Resin takes really long time to save the session.
Description It can take several minutes for Resin to save the session. The server is quite idle when this happens.

I get a lot of these in stderr. (once every 30 seconds or so)
OFFER_FAILED: Block[Table[data:6],3ec006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],330006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3ea006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3f2006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],14006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],350006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3fa006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],34006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3f8006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],370006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3f6006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],390006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],3f4006,copy=false,load=false,dirty=true]
OFFER_FAILED: Block[Table[data:6],2f2006,copy=false,load=false,dirty=true]

The stacktrace for the thread that is taking a lot of time:
Thread 94: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - com.caucho.util.RingBlockerBasic.offerWait(long, java.util.concurrent.atomic.AtomicLong, int, long, java.util.concurrent.TimeUnit) @bci=98, line=81 (Interpreted frame)
 - com.caucho.util.RingValueQueue.offer(java.lang.Object, long, java.util.concurrent.TimeUnit, int) @bci=79, line=174 (Compiled frame)
 - com.caucho.util.RingValueQueue.offer(java.lang.Object, long, java.util.concurrent.TimeUnit) @bci=6, line=151 (Compiled frame)
 - com.caucho.db.block.BlockWriter.addDirtyBlockNoWake(com.caucho.db.block.Block) @bci=25, line=103 (Interpreted frame)
 - com.caucho.db.block.BlockWriter.addDirtyBlock(com.caucho.db.block.Block) @bci=2, line=67 (Compiled frame)
 - com.caucho.db.block.Block.save() @bci=31, line=446 (Compiled frame)
 - com.caucho.db.block.Block.commit() @bci=8, line=353 (Compiled frame)
 - com.caucho.db.xa.DbTransaction.writeData() @bci=56, line=453 (Compiled frame)
 - com.caucho.db.sql.QueryContext.unlock() @bci=143, line=641 (Compiled frame)
 - com.caucho.db.table.Table.insertRow(com.caucho.db.sql.QueryContext, com.caucho.db.xa.DbTransaction, java.util.ArrayList, java.util.ArrayList, com.caucho.db.block.Block, int) @bci=483, line=1095 (Compiled frame)
 - com.caucho.db.table.Table.insert(com.caucho.db.sql.QueryContext, com.caucho.db.xa.DbTransaction, java.util.ArrayList, java.util.ArrayList) @bci=100, line=977 (Interpreted frame)
 - com.caucho.db.sql.InsertQuery.execute(com.caucho.db.sql.QueryContext, com.caucho.db.xa.DbTransaction) @bci=39, line=116 (Interpreted frame)
 - com.caucho.db.jdbc.PreparedStatementImpl.execute() @bci=126, line=367 (Interpreted frame)
 - com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate() @bci=1, line=337 (Interpreted frame)
 - com.caucho.server.distcache.DataStore.insert(java.io.InputStream, int) @bci=37, line=443 (Interpreted frame)
 - com.caucho.server.distcache.DataStore.save(java.io.InputStream, int) @bci=3, line=419 (Interpreted frame)
 - com.caucho.server.distcache.CacheDataBackingImpl.saveData(java.io.InputStream, int) @bci=6, line=282 (Interpreted frame)
 - com.caucho.server.distcache.LocalDataManager.writeData(java.io.InputStream) @bci=17, line=404 (Interpreted frame)
 - com.caucho.server.distcache.DistCacheEntry.putStream(java.io.InputStream, long, long, int, long, long, long, boolean) @bci=10, line=418 (Interpreted frame)
 - com.caucho.server.distcache.DistCacheEntry.put(java.io.InputStream, long, long, long, long) @bci=12, line=351 (Interpreted frame)
 - com.caucho.server.distcache.CacheImpl.put(java.lang.Object, java.io.InputStream, long, long, long, long) @bci=17, line=488 (Interpreted frame)
 - com.caucho.server.session.SessionImpl.save() @bci=124, line=908 (Interpreted frame)
 - com.caucho.server.http.AbstractCauchoRequest.saveSession() @bci=10, line=739 (Interpreted frame)
 - com.caucho.server.http.HttpServletResponseImpl.sendRedirect(java.lang.String) @bci=166, line=1012 (Interpreted frame)
 - se.netset.m4.NodeHttp.doPost() @bci=563, line=241 (Compiled frame)
 - se.netset.m4.NodeHttp.<init>(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) @bci=143, line=62 (Interpreted frame)
 - se.netset.m4.M4Comp.service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) @bci=14, line=209 (Interpreted frame)
 - se.netset.m4.ServletAPIAdapter.doGet(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) @bci=86, line=176 (Interpreted frame)
 - se.netset.m4.ServletAPIAdapter.doPost(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) @bci=3, line=192 (Interpreted frame)
 - javax.servlet.http.HttpServlet.service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) @bci=267, line=159 (Interpreted frame)
 - javax.servlet.http.HttpServlet.service(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=15, line=97 (Interpreted frame)
 - com.caucho.server.dispatch.ServletFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=47, line=109 (Interpreted frame)
 - com.caucho.server.httpcache.ProxyCacheFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=13, line=156 (Interpreted frame)
 - com.caucho.server.webapp.WebAppFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=93, line=156 (Interpreted frame)
 - com.caucho.server.webapp.AccessLogFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=6, line=95 (Interpreted frame)
 - com.caucho.server.dispatch.ServletInvocation.service(javax.servlet.ServletRequest, javax.servlet.ServletResponse) @bci=61, line=289 (Interpreted frame)
 - com.caucho.server.http.HttpRequest.handleRequest() @bci=380, line=838 (Interpreted frame)
 - com.caucho.network.listen.TcpSocketLink.dispatchRequest() @bci=98, line=1345 (Interpreted frame)
 - com.caucho.network.listen.TcpSocketLink.handleRequest() @bci=1, line=1301 (Compiled frame)
 - com.caucho.network.listen.TcpSocketLink.handleRequestsImpl(boolean) @bci=48, line=1285 (Compiled frame)
 - com.caucho.network.listen.TcpSocketLink.handleRequests(boolean) @bci=11, line=1193 (Interpreted frame)
 - com.caucho.network.listen.TcpSocketLink.handleAcceptTaskImpl() @bci=180, line=992 (Interpreted frame)
 - com.caucho.network.listen.ConnectionTask.runThread() @bci=54, line=117 (Interpreted frame)
 - com.caucho.network.listen.ConnectionTask.run() @bci=19, line=93 (Interpreted frame)
 - com.caucho.network.listen.SocketLinkThreadLauncher.handleTasks(boolean) @bci=108, line=169 (Interpreted frame)
 - com.caucho.network.listen.TcpSocketAcceptThread.run() @bci=61, line=61 (Interpreted frame)
 - com.caucho.env.thread2.ResinThread2.runTasks() @bci=158, line=173 (Interpreted frame)
 - com.caucho.env.thread2.ResinThread2.run() @bci=15, line=118 (Interpreted frame)


Resin-Pro-4.0.36
Windows
Win Server 2008 R2 Enterprise
java version "1.7.0_09"
Java(TM) SE Runtime Environment (build 1.7.0_09-b05)
Java HotSpot(TM) 64-Bit Server VM (build 23.5-b02, mixed mode)

Do you need any extra information to track this problem down?
Additional Information
Attached Files

- Relationships

- Notes
(0006363)
ferg
12-06-13 10:10

Is there another thread that's doing the writing that also slow?

That code has two processes connected by message passing. The one above is the sending thread. There's also a consuming thread that takes the block and writes it to disk. The consumer is spawned on demand.

Depending on the thread dump there are two main possible issues:
  1) the writer is stuck somehow (you'd see a thread with another stuck thread)
  2) the messaging system has failed in the notification/spawning (you wouldn't see any other threads, and the system would never write more data.)

In either case, restarting would work around the issue, because it's a memory-based synchronization issue, not a file/data issue.
 
(0006552)
ferg
11-05-14 16:17

Added queue wake() before blocking in this situation to avoid case where queue is fill but worker has not been woken.

Because of the complexities of timing in this area of code, this may be a different issue than observed in the bug report.
 

- Issue History
Date Modified Username Field Change
12-03-13 06:25 Mathias Lagerwall New Issue
12-06-13 10:10 ferg Note Added: 0006363
11-05-14 16:17 ferg Note Added: 0006552
11-05-14 16:17 ferg Assigned To  => ferg
11-05-14 16:17 ferg Status new => closed
11-05-14 16:17 ferg Resolution open => fixed
11-05-14 16:17 ferg Fixed in Version  => 4.0.42


Mantis 1.0.0rc3[^]
Copyright © 2000 - 2005 Mantis Group
31 total queries executed.
27 unique queries executed.
Powered by Mantis Bugtracker