13 Replies Latest reply on Jan 30, 2007 6:01 AM by j.hedin

    Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy load

      We use JBoss 4.0.4.GA + EJB3 RC9 + jBPM 3.1.3 with store in MySQL 5 for our application. The application runs in an active-active cluster on two nodes. The flow is mainly

      MDB (starts TX) -> token.signal() -> jBPM actions (often calls EJB3 SLSB -> EJB3 entity beans) -> JMS send tokenId to queue

      and

      EJB3-timer (starts TX) -> jBPM timers -> jBPM actions (SLSB -> Entity beans) -> JMS send tokenId to queue

      The problem we have is Cache lockups during heavy load. I have tried to tune the cache, but I'll still get the lock. Just before the lock I get the following error


      2007-01-25 10:09:36,573 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:09:52,382 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:10:07,505 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:10:34,717 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:10:57,414 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:11:12,426 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:11:27,430 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:11:42,436 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:11:57,445 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:12:12,452 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:12:27,457 WARN [org.jboss.cache.eviction.LRUAlgorithm] eviction timed out. Will retry later.
      2007-01-25 10:12:36,335 WARN [org.jboss.cache.eviction.Region] putNodeEvent(): eviction node event queue size is at 98% threshold value of capacity: 200000 You will need to reduce the wakeUpIntervalSeconds parameter.
      2007-01-25 10:12:36,365 WARN [org.jboss.cache.eviction.Region] putNodeEvent(): eviction node event queue size is at 98% threshold value of capacity: 200000 You will need to reduce the wakeUpIntervalSeconds parameter.
      2007-01-25 10:12:36,396 WARN [org.jboss.cache.eviction.Region] putNodeEvent(): eviction node event queue size is at 98% threshold value of capacity: 200000 You will need to reduce the wakeUpIntervalSeconds parameter.



      The wakeUpIntervalSeconds is set to 1s.

      On my work station, a Pentium D, I need to disable almost all log via log4j to trigger the lockup. On the test servers with two nodes with 2 Itanium 2 each and JRockit JDK, the lockup can be obtained with extended log4j debug log.

      Is this a configuration mistake by me, or something strange with the Cache?

      This is a repost of a message in the JMS forum, since I first thought it was a JMS lockup.

      http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4006258#4006258


      Stacktrace of a hung JBoss


      =========================================================================

      JBoss Bootstrap Environment

      JBOSS_HOME: /home/johan/jboss-run/jboss-4.0.4.GA

      JAVA: /opt/sun-jdk-1.5.0.10/bin/java

      JAVA_OPTS: -server -Xms128m -Xmx512m -Xdebug -Xrunjdwp:transport=dt_socket,address=8890,server=y,s
      uspend=n -Dprogram.name=run.sh

      CLASSPATH: /home/johan/jboss-run/jboss-4.0.4.GA/bin/run.jar:/home/johan/jboss-run/jboss-4.0.4.GA/l
      ib/bcprov-jdk15-134.jar:/opt/sun-jdk-1.5.0.10/lib/tools.jar

      =========================================================================

      Listening for transport dt_socket at address: 8890
      12:53:14,917 INFO [Server] Starting JBoss (MX MicroKernel)...
      12:53:14,918 INFO [Server] Release ID: JBoss [Zion] 4.0.4.GA (build: CVSTag=JBoss_4_0_4_GA date=200
      605151000)
      12:53:14,920 INFO [Server] Home Dir: /home/johan/jboss-run/jboss-4.0.4.GA
      12:53:14,920 INFO [Server] Home URL: file:/home/johan/jboss-run/jboss-4.0.4.GA/
      12:53:14,921 INFO [Server] Patch URL: null
      12:53:14,921 INFO [Server] Server Name: ibcs
      12:53:14,921 INFO [Server] Server Home Dir: /home/johan/jboss-run/jboss-4.0.4.GA/server/ibcs
      12:53:14,921 INFO [Server] Server Home URL: file:/home/johan/jboss-run/jboss-4.0.4.GA/server/ibcs/
      12:53:14,922 INFO [Server] Server Log Dir: /home/johan/jboss-run/jboss-4.0.4.GA/server/ibcs/log
      12:53:14,922 INFO [Server] Server Temp Dir: /home/johan/jboss-run/jboss-4.0.4.GA/server/ibcs/tmp
      12:53:14,922 INFO [Server] Root Deployment Filename: jboss-service.xml
      12:53:15,293 INFO [ServerInfo] Java version: 1.5.0_10,Sun Microsystems Inc.
      12:53:15,293 INFO [ServerInfo] Java VM: Java HotSpot(TM) Server VM 1.5.0_10-b03,Sun Microsystems In
      c.
      12:53:15,293 INFO [ServerInfo] OS-System: Linux 2.6.18-gentoo-r6,i386
      12:53:15,888 INFO [Server] Core system initialized
      12:53:20,239 INFO [WebService] Using RMI server codebase: http://doloxene:8083/
      12:53:20,277 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
      Full thread dump Java HotSpot(TM) Server VM (1.5.0_10-b03 mixed mode):

      "Timeouts(2)-2" daemon prio=1 tid=0x08ce0eb8 nid=0x6ed6 in Object.wait() [0x7f47b000..0x7f47bf50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x90b2aaf8> (a java.lang.Object)
      at EDU.oswego.cs.dl.util.concurrent.BoundedLinkedQueue.poll(BoundedLinkedQueue.java:253)
      - locked <0x90b2aaf8> (a java.lang.Object)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at org.jboss.util.threadpool.MinPooledExecutor.getTask(MinPooledExecutor.java:106)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "Timeouts(2)-1" daemon prio=1 tid=0x0955b528 nid=0x6ed5 in Object.wait() [0x763a5000..0x763a5fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x90b2aaf8> (a java.lang.Object)
      at EDU.oswego.cs.dl.util.concurrent.BoundedLinkedQueue.poll(BoundedLinkedQueue.java:253)
      - locked <0x90b2aaf8> (a java.lang.Object)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at org.jboss.util.threadpool.MinPooledExecutor.getTask(MinPooledExecutor.java:106)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@a3be41 client=192.168.1.115:8093)#17" daemon prio=1 tid=0x092962b8 nid=0x6ecd in Object.wait() [0x78429000..0x7842a0d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d08cb98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d08cb98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1fa6f6 client=192.168.1.115:53063)#14" daemon prio=1 tid=0x08d2bf10 nid=0x6ecc in Object.wait() [0x77811000..0x77812150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d089798> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d089798> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@10c7242 client=192.168.1.115:33728)#12" daemon prio=1 tid=0x09f96dc0 nid=0x6ecb in Object.wait() [0x7f175000..0x7f1761d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d084520> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d084520> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1c37681 client=192.168.1.115:8093)#19" daemon prio=1 tid=0x0aaadc20 nid=0x6eca in Object.wait() [0x8067b000..0x8067be50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d07bf98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d07bf98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@166f1f2 client=192.168.1.115:39028)#8" daemon prio=1 tid=0x09c1a3a0 nid=0x6ec9 in Object.wait() [0x72cfe000..0x72cfeed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0772e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0772e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@3d62ba client=192.168.1.115:52241)#23" daemon prio=1 tid=0x88fb4b40 nid=0x6ec8 in Object.wait() [0x71ffa000..0x71ffaf50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d067eb8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d067eb8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1a9dcd client=192.168.1.115:8093)#17" daemon prio=1 tid=0x73e48860 nid=0x6ec4 in Object.wait() [0x71f79000..0x71f79fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfe58d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfe58d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@16e1fa2 client=192.168.1.115:51368)#13" daemon prio=1 tid=0x0945f410 nid=0x6ec3 in Object.wait() [0x769b1000..0x769b2050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfe24d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfe24d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1d69977 client=192.168.1.115:8093)#19" daemon prio=1 tid=0x08bb9f08 nid=0x6ec2 in Object.wait() [0x799d4000..0x799d50d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfdf090> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfdf090> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1f57ea1 client=192.168.1.115:58979)#18" daemon prio=1 tid=0x08ecbc80 nid=0x6ec1 in Object.wait() [0x794ca000..0x794cb150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfdbc90> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfdbc90> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@4acaad client=192.168.1.115:8093)#20" daemon prio=1 tid=0x08dc5078 nid=0x6ec0 in Object.wait() [0x7bd0d000..0x7bd0e1d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfd8838> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfd8838> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@14e9f98 client=192.168.1.115:8093)#20" daemon prio=1 tid=0x08d204e0 nid=0x6ebf in Object.wait() [0x75589000..0x75589e50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfd5d10> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfd5d10> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@530b56 client=192.168.1.115:8093)#15" daemon prio=1 tid=0x74699f38 nid=0x6eac in Object.wait() [0x785ac000..0x785acfd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172c3d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172c3d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1c251c8 client=192.168.1.115:55186)#12" daemon prio=1 tid=0x72fbf398 nid=0x6eab in Object.wait() [0x7682e000..0x7682f050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172c1d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172c1d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@edf430 client=192.168.1.115:8093)#18" daemon prio=1 tid=0x0a3295e8 nid=0x6eaa in Object.wait() [0x79bd8000..0x79bd90d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172c3e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172c3e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@4e87b4 client=192.168.1.115:8093)#17" daemon prio=1 tid=0x08ef3670 nid=0x6ea9 in Object.wait() [0x7750b000..0x7750c150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172c1b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172c1b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@12479fc client=192.168.1.115:8093)#8" daemon prio=1 tid=0x081e02f8 nid=0x6e89 in Object.wait() [0x7f0f4000..0x7f0f4ed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d06f208> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d06f208> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@169b8b8 client=192.168.1.115:8093)#6" daemon prio=1 tid=0x08d359e0 nid=0x6e88 in Object.wait() [0x795cc000..0x795ccf50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d06c370> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d06c370> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1a3a87c client=192.168.1.115:8093)#13" daemon prio=1 tid=0x08ccfef0 nid=0x6e87 in Object.wait() [0x781a4000..0x781a4fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d07eac0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d07eac0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1d2a83 client=192.168.1.115:51665)#9" daemon prio=1 tid=0x74286c28 nid=0x6e86 in Object.wait() [0x77a96000..0x77a97050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d071858> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d071858> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1947e6f client=192.168.1.115:8093)#19" daemon prio=1 tid=0x096366d8 nid=0x6e85 in Object.wait() [0x6dcf2000..0x6dcf30d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0826e0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0826e0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@480441 client=192.168.1.115:8093)#14" daemon prio=1 tid=0x08d2ed50 nid=0x6e84 in Object.wait() [0x79851000..0x79852150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0808d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0808d0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1f3fb9e client=192.168.1.115:8093)#15" daemon prio=1 tid=0x0972bdd0 nid=0x6e83 in Object.wait() [0x6ddf4000..0x6ddf51d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d087070> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d087070> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@183a7c3 client=192.168.1.115:54240)#10" daemon prio=1 tid=0x09885f30 nid=0x6e82 in Object.wait() [0x788b2000..0x788b2e50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0754b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0754b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@f7ef0 client=192.168.1.115:37356)#11" daemon prio=1 tid=0x08bec698 nid=0x6e81 in Object.wait() [0x78225000..0x78225ed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d073688> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d073688> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@3b27b1 client=192.168.1.115:8093)#14" daemon prio=1 tid=0x0b0abac8 nid=0x6e7a in Object.wait() [0x71d75000..0x71d761d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d01fde0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d01fde0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@9e100e client=192.168.1.115:8093)#16" daemon prio=1 tid=0x091deeb8 nid=0x6e76 in Object.wait() [0x86451000..0x86451fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d011848> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d011848> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1387ba3 client=192.168.1.115:57741)#14" daemon prio=1 tid=0x09054668 nid=0x6e75 in Object.wait() [0x6df77000..0x6df78050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d00f650> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d00f650> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@834b4f client=192.168.1.115:8093)#15" daemon prio=1 tid=0x0971ab80 nid=0x6e74 in Object.wait() [0x7c925000..0x7c9260d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d008360> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d008360> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@e75830 client=192.168.1.115:40378)#11" daemon prio=1 tid=0x093cfa60 nid=0x6e73 in Object.wait() [0x7bc8c000..0x7bc8d150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d006168> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d006168> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@dbe104 client=192.168.1.115:8093)#14" daemon prio=1 tid=0x089685a8 nid=0x6e72 in Object.wait() [0x77286000..0x772871d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d003f30> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d003f30> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1bd423e client=192.168.1.115:44745)#16" daemon prio=1 tid=0x7fd30428 nid=0x6e6e in Object.wait() [0x7ecec000..0x7ececed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d001e60> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d001e60> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1710088 client=192.168.1.115:54336)#20" daemon prio=1 tid=0x73e47488 nid=0x6e35 in Object.wait() [0x7b884000..0x7b8850d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d00aea0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d00aea0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@175ad85 client=192.168.1.115:8093)#9" daemon prio=1 tid=0x09f979e0 nid=0x6e08 in Object.wait() [0x6de75000..0x6de75fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d01cc68> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d01cc68> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1c34d24 client=192.168.1.115:8093)#12" daemon prio=1 tid=0x881f9960 nid=0x6e07 in Object.wait() [0x7cd2d000..0x7cd2e050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d021a98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d021a98> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@18bbe12 client=192.168.1.115:8093)#15" daemon prio=1 tid=0x881f9b18 nid=0x6e05 in Object.wait() [0x7b5f1000..0x7b5f2150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d01e578> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d01e578> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@511213 client=192.168.1.115:51299)#12" daemon prio=1 tid=0x88f70198 nid=0x6e04 in Object.wait() [0x7caa8000..0x7caa91d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d016c40> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d016c40> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1ca175 client=192.168.1.115:45666)#10" daemon prio=1 tid=0x7259e710 nid=0x6e03 in Object.wait() [0x7297d000..0x7297de50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d01a8c0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d01a8c0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@4edbad client=192.168.1.115:42126)#9" daemon prio=1 tid=0x0921a670 nid=0x6e02 in Object.wait() [0x80b40000..0x80b40ed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0153b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0153b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1ac282e client=192.168.1.115:56069)#13" daemon prio=1 tid=0x08e4b860 nid=0x6e01 in Object.wait() [0x7cdae000..0x7cdaef50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d019000> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d019000> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1f9d5b5 client=192.168.1.115:8093)#17" daemon prio=1 tid=0x099a0dd0 nid=0x6dfc in Object.wait() [0x7196d000..0x7196e150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d00d960> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d00d960> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@196081a client=192.168.1.115:34626)#14" daemon prio=1 tid=0x09a888d8 nid=0x6dea in Object.wait() [0x73379000..0x7337a0d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172bd30> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172bd30> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@ea3542 client=192.168.1.115:60026)#13" daemon prio=1 tid=0x743fb030 nid=0x6de9 in Object.wait() [0x85e45000..0x85e46150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0xa172bac0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0xa172bac0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@382dc4 client=192.168.1.115:8093)#3" daemon prio=1 tid=0x09f96f90 nid=0x6ddf in Object.wait() [0x6e0fa000..0x6e0fae50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d383150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d383150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1ee4d85 client=192.168.1.115:8093)#16" daemon prio=1 tid=0x0835f508 nid=0x6d99 in Object.wait() [0x78ebe000..0x78ebeed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d01c150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d01c150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@48141c client=192.168.1.115:44665)#10" daemon prio=1 tid=0x0922a7e0 nid=0x6d91 in Object.wait() [0x80fc9000..0x80fc9ed0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0184c8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0184c8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@335c3b client=192.168.1.115:46372)#13" daemon prio=1 tid=0x093fb5d8 nid=0x6d8d in Object.wait() [0x719ee000..0x719ef0d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d00c5d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d00c5d8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1a82c2f client=192.168.1.115:8093)#12" daemon prio=1 tid=0x08ffa6d8 nid=0x6d86 in Object.wait() [0x793c8000..0x793c8f50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0011b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0011b8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@42c183 client=192.168.1.115:8093)#10" daemon prio=1 tid=0x097b0a88 nid=0x6d82 in Object.wait() [0x76fbd000..0x76fbe150]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cff91a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cff91a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@aeadc0 client=192.168.1.115:45026)#14" daemon prio=1 tid=0x084f6898 nid=0x6d81 in Object.wait() [0x6d4e2000..0x6d4e31d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cff7c28> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cff7c28> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1d2a177 client=192.168.1.115:59363)#19" daemon prio=1 tid=0x098d9a38 nid=0x6d7e in Object.wait() [0x79ede000..0x79edef50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfd3eb0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfd3eb0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@1f3f3e client=192.168.1.115:8093)#7" daemon prio=1 tid=0x0a97ddd0 nid=0x6d05 in Object.wait() [0x7d339000..0x7d339fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d00d150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d00d150> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@347f58 client=192.168.1.115:39127)#13" daemon prio=1 tid=0x09a692c8 nid=0x6cdb in Object.wait() [0x732f8000..0x732f8fd0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8cfd3668> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8cfd3668> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@183f39f client=192.168.1.115:50152)#3" daemon prio=1 tid=0x08faede0 nid=0x6bcc in Object.wait() [0x6fefa000..0x6fefaf50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d382138> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d382138> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2.SocketManager.WriteTask#144 client=192.168.1.115:50152" daemon prio=1 tid=0x881faca0 nid=0x6bc9 in Object.wait() [0x6d9ec000..0x6d9ed0d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x9426c6e8> (a java.lang.Object)
      at java.lang.Object.wait(Object.java:474)
      at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(LinkedQueue.java:122)
      - locked <0x9426c6e8> (a java.lang.Object)
      at org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:519)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2.SocketManager.ReadTask#143 client=192.168.1.115:50152" daemon prio=1 tid=0x893d8db0 nid=0x6bc8 runnable [0x6d8ea000..0x6d8eb150]
      at java.net.SocketInputStream.socketRead0(Native Method)
      at java.net.SocketInputStream.read(SocketInputStream.java:129)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:235)
      - locked <0x9426cf48> (a org.jboss.util.stream.NotifyingBufferedInputStream)
      at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79)
      at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2196)
      at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2376)
      at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2443)
      at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2515)
      at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2664)
      at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2.SocketManager.WriteTask#142 client=192.168.1.115:8093" daemon prio=1 tid=0x098da1d0 nid=0x6bc7 in Object.wait() [0x6d96c000..0x6d96c1d0]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x9426cff0> (a java.lang.Object)
      at java.lang.Object.wait(Object.java:474)
      at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(LinkedQueue.java:122)
      - locked <0x9426cff0> (a java.lang.Object)
      at org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:519)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2.SocketManager.ReadTask#141 client=192.168.1.115:8093" daemon prio=1 tid=0x09368958 nid=0x6bc6 runnable [0x77e9e000..0x77e9ee50]
      at java.net.SocketInputStream.socketRead0(Native Method)
      at java.net.SocketInputStream.read(SocketInputStream.java:129)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:235)
      - locked <0x9426d860> (a org.jboss.util.stream.NotifyingBufferedInputStream)
      at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79)
      at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2196)
      at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2376)
      at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2443)
      at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2515)
      at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2664)
      at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
      at java.lang.Thread.run(Thread.java:595)

      "UIL2(SocketManager.MsgPool@5a128d client=192.168.1.115:37890)#19" daemon prio=1 tid=0x89e44b38 nid=0x6b35 in Object.wait() [0x7cb29000..0x7cb2a050]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x8d0001a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(SynchronousChannel.java:353)
      - locked <0x8d0001a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(PooledExecutor.java:723)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:747)
      at java.lang.Thread.run(Thread.java:595)

      "WorkManager(4)-186" daemon prio=1 tid=0x8a0a0aa8 nid=0x69e2 in Object.wait() [0x6fffa000..0x6fffcf50]
      at java.lang.Object.wait(Native Method)
      - waiting on <0x91b55388> (a java.lang.Object)
      at java.lang.Object.wait(Object.java:474)
      at EDU.oswego.cs.dl.util.concurrent.BoundedBuffer.put(BoundedBuffer.java:109)
      - locked <0x91b55388> (a java.lang.Object)
      at org.jboss.cache.eviction.Region.putNodeEvent(Region.java:121)
      at org.jboss.cache.eviction.Region.setAddedNode(Region.java:97)
      at org.jboss.cache.eviction.LRUPolicy.nodeAdded(LRUPolicy.java:56)
      at org.jboss.cache.eviction.LRUPolicy.nodeCreated(LRUPolicy.java:94)
      at org.jboss.cache.TreeCache.notifyNodeCreated(TreeCache.java:4268)
      at org.jboss.cache.Node.getOrCreateChild(Node.java:283)
      - locked <0x9351bd48> (a java.lang.Object)
      at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:214
      )
      at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:1
      62)
      at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
      at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:35)
      at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
      at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:56)
      at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:4172)
      at org.jboss.cache.TreeCache.putFailFast(TreeCache.java:2880)
      at org.hibernate.cache.TreeCache.put(TreeCache.java:74)
      at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:58)
      at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
      at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
      at org.hibernate.loader.Loader.doQuery(Loader.java:717)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
      at org.hibernate.loader.Loader.loadCollection(Loader.java:1918)
      at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:36)
      at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPers
      ister.java:565)
      at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultI
      nitializeCollectionEventListener.java:60)
      at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716)
      at org.hibernate.collection.AbstractPersistentCollection.forceInitialization(AbstractPersistentColl
      ection.java:454)
      at org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistence
      Context.java:755)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:229)
      at org.hibernate.loader.Loader.doList(Loader.java:2144)
      at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
      at org.hibernate.loader.Loader.list(Loader.java:2023)
      at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
      at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
      at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
      at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
      at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
      at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
      at se.ecare.ib.ejb.entity.Request.findByStartAndStop(Request.java:699)
      at se.ecare.ib.ejb.session.AdvancedSearchBean.indexRequestsFrom(AdvancedSearchBean.java:122)
      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:585)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
      at se.ecare.ib.ejb.session.DataAccess.throwDataReadFault(DataAccess.java:39)
      at sun.reflect.GeneratedMethodAccessor679.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:146)
      at se.ecare.ib.ejb.session.ExceptionHandler.enshureFaultLoggedAnRollback(ExceptionHandler.java:70)
      at sun.reflect.GeneratedMethodAccessor239.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118)
      at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:6
      3)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityMa
      nagerInterceptor.java:54)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:201)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:6
      2)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.security.RoleBasedAuthorizationInterceptor.invoke(RoleBasedAuthorizationInterc
      eptor.java:167)
      at org.jboss.ejb3.security.RoleBasedAuthorizationInterceptor.invoke(RoleBasedAuthorizationIntercept
      or.java:108)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:78)
      at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:
      131)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:211)
      at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:79)
      at $Proxy148.indexRequestsFrom(Unknown Source)
      at se.ecare.ib.logic.gop.OrderReindexClusterNode.execute(OrderReindexClusterNode.java:61)
      at org.jbpm.graph.def.Action.execute(Action.java:123)
      at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Action_$$_javassist_62.execute(Action_$$_javassist_62.java)
      at org.jbpm.graph.def.Node.execute(Node.java:328)
      at org.jbpm.graph.def.Node.enter(Node.java:316)
      at sun.reflect.GeneratedMethodAccessor101.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Node_$$_javassist_46.enter(Node_$$_javassist_46.java)
      at org.jbpm.graph.def.Transition.take(Transition.java:119)
      at org.jbpm.graph.def.Node.leave(Node.java:383)
      at sun.reflect.GeneratedMethodAccessor99.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Node_$$_javassist_46.leave(Node_$$_javassist_46.java)
      at org.jbpm.graph.exe.Token.signal(Token.java:178)
      at org.jbpm.graph.exe.Token.signal(Token.java:123)
      at sun.reflect.GeneratedMethodAccessor240.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.exe.Token_$$_javassist_63.signal(Token_$$_javassist_63.java)
      at se.ecare.common.gop.DetatchTransactionInput.onMessage(DetatchTransactionInput.java:140)
      at sun.reflect.GeneratedMethodAccessor109.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
      at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:6
      3)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityMa
      nagerInterceptor.java:54)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:201)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:6
      2)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.security.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:79)
      at org.jboss.ejb3.security.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:63)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:245)
      at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
      at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
      at $Proxy138.onMessage(Unknown Source)
      at org.jboss.resource.adapter.jms.inflow.JmsServerSession.onMessage(JmsServerSession.java:183)
      at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:902)
      at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)
      at org.jboss.mq.SpySession.run(SpySession.java:323)
      - locked <0x931eb860> (a java.util.LinkedList)
      at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:249)
      at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
      at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
      at java.lang.Thread.run(Thread.java:595)

      "WorkManager(4)-177" daemon prio=1 tid=0x88bb47f0 nid=0x68d5 waiting for monitor entry [0x7588d000..0x7588ff50]
      at org.jboss.cache.Node.getOrCreateChild(Node.java:270)
      - waiting to lock <0x9351bbf8> (a java.lang.Object)
      at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:214
      )
      at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:1
      62)
      at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
      at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:35)
      at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
      at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:56)
      at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:4172)
      at org.jboss.cache.TreeCache.putFailFast(TreeCache.java:2880)
      at org.hibernate.cache.TreeCache.put(TreeCache.java:74)
      at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:58)
      at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
      at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
      at org.hibernate.loader.Loader.doQuery(Loader.java:717)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
      at org.hibernate.loader.Loader.loadEntity(Loader.java:1784)
      at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
      at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
      at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2977)
      at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.jav
      a:393)
      at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:374)
      at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:137)
      at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:193)
      at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:101)
      at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
      at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
      at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
      at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
      at org.jboss.ejb3.entity.TransactionScopedEntityManager.find(TransactionScopedEntityManager.java:16
      4)
      at se.ecare.ib.ejb.session.DataExportManagementBean.continuousExport(DataExportManagementBean.java:
      252)
      at sun.reflect.GeneratedMethodAccessor392.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
      at se.ecare.ib.ejb.session.ExceptionHandler.enshureFaultLoggedAnRollback(ExceptionHandler.java:70)
      at sun.reflect.GeneratedMethodAccessor239.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118)
      at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:6
      3)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityMa
      nagerInterceptor.java:54)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:201)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:6
      2)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.security.RoleBasedAuthorizationInterceptor.invoke(RoleBasedAuthorizationInterc
      eptor.java:167)
      at org.jboss.ejb3.security.RoleBasedAuthorizationInterceptor.invoke(RoleBasedAuthorizationIntercept
      or.java:108)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:78)
      at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:
      131)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:211)
      at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:79)
      at $Proxy139.continuousExport(Unknown Source)
      at se.ecare.ib.logic.gop.CreateExportMessages.execute(CreateExportMessages.java:63)
      at org.jbpm.graph.def.Action.execute(Action.java:123)
      at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Action_$$_javassist_62.execute(Action_$$_javassist_62.java)
      at org.jbpm.graph.def.Node.execute(Node.java:328)
      at org.jbpm.graph.def.Node.enter(Node.java:316)
      at sun.reflect.GeneratedMethodAccessor101.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Node_$$_javassist_46.enter(Node_$$_javassist_46.java)
      at org.jbpm.graph.def.Transition.take(Transition.java:119)
      at org.jbpm.graph.def.Node.leave(Node.java:383)
      at sun.reflect.GeneratedMethodAccessor99.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)
      at org.jbpm.graph.def.Node_$$_javassist_46.leave(Node_$$_javassist_46.java)
      at org.jbpm.graph.exe.Token.signal(Token.java:178)
      at org.jbpm.graph.exe.Token.signal(Token.java:123)
      at sun.reflect.GeneratedMethodAccessor240.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java
      :208)


        • 1. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo
          manik

          Hmm, I think I know what is going on. What version of JBoss Cache are you using?

          One problem I've seen is that the eviction queue size is fixed to 200000. If you have sufficient load, you could quickly swamp this and cause a lock up.

          http://jira.jboss.com/jira/browse/JBCACHE-684

          We've fixed it in 2.0.0, where you can configure the size of this queue. It is easy enough to backport to the 1.4.x branch; something you could do if you wanted to and contribute back, even. :-)

          • 2. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

            Tanks for the quick reply!

            We're using 1.2.4.SP2 as included in JBoss 4.0.4. Is it safe to upgrade to 1.4 with JBoss 4.0.4 and EJB3? What about 2.0?

            If 2.0 is not possible for JBoss 4.0.4 + EJB3. We'll look into the backport. Just give us a hint of where to start looking.

            • 3. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

              I should have done my homework and checked this before posting. 1.4.1 looks fine. 2.0 is in alpha, so we can't use that. I have been looking a bit into 2.0ALPHA2 source, but I could use a hint of where to start for the backport to 1.4.1

              • 4. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

                Found it. It's in

                src/org/jboss/cache/config/EvictionRegionConfig.java

                and

                src/org/jboss/cache/RegionImpl.java

                (will look further). If I would read source more and post less, both the backport and my S/N ration would be better ;-)

                • 5. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo
                  genman

                  From what I see in the logs, what's causing failure is accumulation. Accumulation is being caused by eviction is timing out (i.e. TimeoutException is being thrown.) Then the queue can't be processed very quickly.

                  Seems like the evict needs to not wait too long.

                  • 6. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo
                    manik

                    Yes, this is the other thing. When doing an eviction the lock acquisition timeout should be set to 0 so if it cannot acquire the lock it fails immediately.

                    • 7. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo
                      brian.stansberry

                      PessimisticLockInterceptor does that in 1.4.1.GA. Not sure when that was introduced.

                      • 8. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

                        Upgrading JBoss Cache to 1.4.1 did sole the lockup problem for at least the single node cluster on Pentium D. However, we can't use this combination due to the problem with EJB3 clustered SFSB on JBoss 4.0.4 and JBoss Cache > 1.2.x.

                        I will upgrade to JBoss 4.0.5.GA an EJB3-RC9_Patch_1 and test on both the single cluster node and on the Itanium test cluster. The upgrade should be smooth since all our JBoss configuration is done through ant and XLST.

                        • 9. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

                          Looks like JBoss 4.0.5.GA + EJB3 RC9 patch 1 solves the lockup problem for the single node Pentium D cluster. On the Itanium cluster a signle node looks fine (will report more after longer tests). However, I can't start the second node on a loaded cluster. The EJB3 deployment fails with the following error


                          2007-01-28 22:52:17,475 ERROR [org.jboss.cache.TreeCache] failed to activate /se
                          /ecare/ib/ejb/entity/Priority
                          org.jboss.cache.CacheException: Failed getting state due to timeout on othernode
                          -ext1:33264
                          at org.jboss.cache.TreeCache._loadState(TreeCache.java:2076)
                          at org.jboss.cache.TreeCache.loadState(TreeCache.java:1933)
                          at org.jboss.cache.TreeCache.activateRegion(TreeCache.java:1825)
                          at org.jboss.ejb3.entity.JBCCache.activateCacheRegion(JBCCache.java:293)
                          at org.jboss.ejb3.entity.JBCCache.(JBCCache.java:61)
                          at org.jboss.ejb3.entity.TreeCacheProviderHook.buildCache(TreeCacheProvi
                          derHook.java:58)
                          at org.hibernate.cache.CacheFactory.createCache(CacheFactory.java:61)
                          at org.hibernate.impl.SessionFactoryImpl.(SessionFactoryImpl.java:
                          214)
                          at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.jav
                          a:1218)
                          at org.hibernate.ejb.Ejb3Configuration.buildEntityManagerFactory(Ejb3Con
                          figuration.java:691)
                          at org.hibernate.ejb.HibernatePersistence.createContainerEntityManagerFa
                          ctory(HibernatePersistence.java:127)
                          at org.jboss.ejb3.entity.PersistenceUnitDeployment.start(PersistenceUnit
                          Deployment.java:264)
                          at jrockit.reflect.VirtualNativeMethodInvoker.invoke(Ljava.lang.Object;[
                          Ljava.lang.Object;)Ljava.lang.Object;(Unknown Source)
                          at java.lang.reflect.Method.invoke(Ljava.lang.Object;[Ljava.lang.Object;
                          J)Ljava.lang.Object;(Unknown Source)
                          at org.jboss.ejb3.ServiceDelegateWrapper.startService(ServiceDelegateWra
                          pper.java:102)
                          at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanS
                          upport.java:289)
                          at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMB
                          eanSupport.java:245)
                          at jrockit.reflect.VirtualNativeMethodInvoker.invoke(Ljava.lang.Object;[
                          Ljava.lang.Object;)Ljava.lang.Object;(Unknown Source)
                          at java.lang.reflect.Method.invoke(Ljava.lang.Object;[Ljava.lang.Object;
                          J)Ljava.lang.Object;(Unknown Source)
                          at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatch
                          er.java:155)
                          at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
                          at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
                          at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.
                          java:264)
                          at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
                          at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceControl
                          ler.java:978)
                          at $Proxy0.start()V(Unknown Source)
                          Ca


                          • 10. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

                            I can now confirm that the lockup problem is gone in JBoss 4.0.5.A + EJB3-RC9-Patch-1. The backport of the eviction queue size is in danger then. The lock time out fix look sufficient.

                            As for the deployment error on a highly loaded server, I will repost it to the EJB3 forum.

                            Tanks all for the quick and helpfull help.

                            • 12. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo
                              kgrjb

                              im using JBossCache 1.4.1.GA with Hibernate 3.2.2.GA and i get a huge number of similar read locks and write locks warns + errors, especially during eviction stage. Then the cache and therefore application fail completely.

                              2007-01-30 12:50:33,443 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#46618 timed out. Will retry later.
                              2007-01-30 12:50:38,447 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47990 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@643b5e09)
                              2007-01-30 12:50:38,448 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47990 timed out. Will retry later.
                              2007-01-30 12:50:43,452 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47989 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@759ad447)
                              2007-01-30 12:50:43,452 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47989 timed out. Will retry later.
                              2007-01-30 12:50:48,456 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47985 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@7e6bda3)
                              2007-01-30 12:50:48,456 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47985 timed out. Will retry later.
                              2007-01-30 12:50:53,679 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6603 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@14a5ca64)
                              2007-01-30 12:50:53,680 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6603 timed out. Will retry later.
                              2007-01-30 12:50:58,685 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47957 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@3dac1c62)
                              2007-01-30 12:50:58,685 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47957 timed out. Will retry later.
                              2007-01-30 12:51:03,689 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47994 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@6f7da7f3)
                              2007-01-30 12:51:03,689 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47994 timed out. Will retry later.
                              2007-01-30 12:51:08,693 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#48005 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@229d7bb4)
                              2007-01-30 12:51:08,694 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#48005 timed out. Will retry later.
                              2007-01-30 12:51:13,698 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47937 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@1124782d)
                              2007-01-30 12:51:13,698 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47937 timed out. Will retry later.
                              2007-01-30 12:51:18,702 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47921 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@714ddb25)
                              2007-01-30 12:51:18,702 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47921 timed out. Will retry later.
                              2007-01-30 12:51:23,707 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47998 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@7abcd35b)
                              2007-01-30 12:51:23,707 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47998 timed out. Will retry later.
                              2007-01-30 12:51:28,711 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#46804 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@2e6e9440)
                              2007-01-30 12:51:28,711 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#46804 timed out. Will retry later.
                              2007-01-30 12:51:33,715 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47841 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@6fad6625)
                              2007-01-30 12:51:33,715 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47841 timed out. Will retry later.
                              2007-01-30 12:51:38,720 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47473 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@216d45f)
                              2007-01-30 12:51:38,720 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47473 timed out. Will retry later.
                              2007-01-30 12:51:43,724 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6655 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@5dc70d90)
                              2007-01-30 12:51:43,724 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6655 timed out. Will retry later.
                              2007-01-30 12:51:48,728 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#48001 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@33a31a74)
                              2007-01-30 12:51:48,728 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#48001 timed out. Will retry later.
                              2007-01-30 12:51:53,733 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47953 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@191dd028)
                              2007-01-30 12:51:53,733 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47953 timed out. Will retry later.
                              2007-01-30 12:51:58,737 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47896 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@744cfef9)
                              2007-01-30 12:51:58,737 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47896 timed out. Will retry later.
                              2007-01-30 12:52:03,741 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6869 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@5ffd6c67)
                              2007-01-30 12:52:03,742 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6869 timed out. Will retry later.
                              2007-01-30 12:52:08,746 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47760 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@76d80f6c)
                              2007-01-30 12:52:08,746 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47760 timed out. Will retry later.
                              2007-01-30 12:52:13,750 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47965 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@62dcb868)
                              2007-01-30 12:52:13,750 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47965 timed out. Will retry later.
                              2007-01-30 12:52:18,754 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6856 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@32bb9ea8)
                              2007-01-30 12:52:18,755 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6856 timed out. Will retry later.
                              2007-01-30 12:52:23,759 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6868 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@8cee68d)
                              2007-01-30 12:52:23,759 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6868 timed out. Will retry later.
                              2007-01-30 12:52:28,763 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6723 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@4782377f)
                              2007-01-30 12:52:28,763 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6723 timed out. Will retry later.
                              2007-01-30 12:52:33,767 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6703 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@36099786)
                              2007-01-30 12:52:33,768 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6703 timed out. Will retry later.
                              2007-01-30 12:52:38,772 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47905 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@1c7ba502)
                              2007-01-30 12:52:38,772 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47905 timed out. Will retry later.
                              2007-01-30 12:52:43,776 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#45812 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@798e34e9)
                              2007-01-30 12:52:43,776 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#45812 timed out. Will retry later.
                              2007-01-30 12:52:48,781 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6595 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@6733eb57)
                              2007-01-30 12:52:48,781 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6595 timed out. Will retry later.
                              2007-01-30 12:52:53,785 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#6627 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@19fd1b0)
                              2007-01-30 12:52:53,785 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#6627 timed out. Will retry later.
                              2007-01-30 12:52:58,789 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47630 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@18d35c85)
                              2007-01-30 12:52:58,790 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47630 timed out. Will retry later.
                              2007-01-30 12:53:03,794 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#46618 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@64cf8d8)
                              2007-01-30 12:53:03,794 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#46618 timed out. Will retry later.
                              2007-01-30 12:53:08,798 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47990 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@643b5e09)
                              2007-01-30 12:53:08,798 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47990 timed out. Will retry later.
                              2007-01-30 12:53:13,802 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47989 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@759ad447)
                              2007-01-30 12:53:13,803 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47989 timed out. Will retry later.
                              2007-01-30 12:53:18,807 ERROR [IdentityLock] read lock for zzz/domain/model/Offer/zzz.domain.model.Offer#47985 could not be acquired by Thread[Timer-7,5,jboss] after 0 ms. Locks: Read lock owners: []
                              Write lock owner: GlobalTransaction:<122.100.2.40:33397>:14383
                              , lock info: write owner=GlobalTransaction:<122.100.2.40:33397>:14383 (org.jboss.cache.lock.LockStrategyReadCommitted@7e6bda3)
                              2007-01-30 12:53:18,807 WARN [BaseEvictionAlgorithm] eviction of zzz/domain/model/Offer/zzz.domain.model.Offer#47985 timed out. Will retry later.

                              • 13. Re: Cache lockup in JBoss 4.0.4.GA + EJB3 RC9 under heavy lo

                                We do also get locks like that, but since our EJB3/hibernate layer uses opportunistic locks, we do have a replay mechanism for the lock/deadlock situations. Those errors are suppressed in the logs.