Jeff Schnitzer wrote:
> Neither <ee:Startup/> nor <resin:Service/> has any observable effect.
> There's definitely some sort of cpu loop; as soon as I enqueue one
> entry, one core goes to 99% for the java process. Occasionally the
> thread hops between cores.
>
Thanks. The loop is unrelated to EJB or JMS.
The spin is related to changes in the sync/locking in the thread/alarm
code, moving to atomic locks where possible.
-- Scott
> * It happens with both jms:FileQueue and jms:MemoryQueue.
> * There seems to be a 1 or 2 second delay before the CPU pegs.
>
> There's nothing obvious to me in the thread dump, but here it is...
>
> 2010-07-20 17:01:15
> Full thread dump Java HotSpot(TM) 64-Bit Server VM (16.3-b01-279 mixed mode):
>
> "resin-11" daemon prio=5 tid=101aca000 nid=0x1185fb000 waiting on
> condition [1185fa000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-10" daemon prio=5 tid=101ac9000 nid=0x1184f8000 runnable [1184f7000]
> java.lang.Thread.State: RUNNABLE
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:129)
> at java.net.SocketInputStream.read(SocketInputStream.java:182)
> at
> com.caucho.hessian.io.Hessian2StreamingInput$StreamingInputStream.readChunkLength(Hessian2StreamingInput.java:241)
> at
> com.caucho.hessian.io.Hessian2StreamingInput$StreamingInputStream.startPacket(Hessian2StreamingInput.java:167)
> at
> com.caucho.hessian.io.Hessian2StreamingInput.startPacket(Hessian2StreamingInput.java:94)
> at com.caucho.hmtp.HmtpReader.readPacket(HmtpReader.java:102)
> at com.caucho.hmtp.HmtpLink.run(HmtpLink.java:111)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:169)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "process reaper" daemon prio=5 tid=101a89800 nid=0x1183f5000 runnable
> [1183f4000]
> java.lang.Thread.State: RUNNABLE
> at java.lang.UNIXProcess.waitForProcessExit(Native Method)
> at java.lang.UNIXProcess.access$900(UNIXProcess.java:17)
> at java.lang.UNIXProcess$2$1.run(UNIXProcess.java:86)
>
> "watchdog-" daemon prio=5 tid=10199c800 nid=0x1181a6000 in
> Object.wait() [1181a5000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <106b74888> (a java.lang.UNIXProcess)
> at java.lang.Object.wait(Object.java:485)
> at java.lang.UNIXProcess.waitFor(UNIXProcess.java:115)
> - locked <106b74888> (a java.lang.UNIXProcess)
> at
> com.caucho.boot.WatchdogChildProcess.run(WatchdogChildProcess.java:145)
> at com.caucho.boot.WatchdogChildTask.run(WatchdogChildTask.java:174)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:169)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "watchdog-process-log-0-1" daemon prio=5 tid=10199c000 nid=0x1180a3000
> runnable [1180a2000]
> java.lang.Thread.State: RUNNABLE
> at java.io.FileInputStream.readBytes(Native Method)
> at java.io.FileInputStream.read(FileInputStream.java:199)
> at
> java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:227)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
> - locked <106b76e48> (a java.io.BufferedInputStream)
> at
> com.caucho.boot.WatchdogChildProcess$WatchdogProcessLogThread.run(WatchdogChildProcess.java:745)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:169)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-7" daemon prio=5 tid=10199b000 nid=0x117fa0000 waiting on
> condition [117f9f000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-6" daemon prio=5 tid=10199a800 nid=0x117e9d000 waiting on
> condition [117e9c000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-5" daemon prio=5 tid=1031c1800 nid=0x117d9a000 waiting on
> condition [117d99000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-4" daemon prio=5 tid=1031c0800 nid=0x117c97000 waiting on
> condition [117c96000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-3" daemon prio=5 tid=1031c0000 nid=0x117b94000 waiting on
> condition [117b93000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-2" daemon prio=5 tid=1031bf000 nid=0x117a91000 waiting on
> condition [117a90000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "resin-1" daemon prio=5 tid=1031be800 nid=0x11798e000 waiting on
> condition [11798d000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at com.caucho.env.thread.ResinThread.waitForTask(ResinThread.java:199)
> at com.caucho.env.thread.ResinThread.runTasks(ResinThread.java:157)
> at com.caucho.env.thread.ResinThread.run(ResinThread.java:126)
>
> "com.caucho.util.alarm$coordinatorthr...@39dd3812-1" daemon prio=10
> tid=101999800 nid=0x11788b000 runnable [11788a000]
> java.lang.Thread.State: RUNNABLE
> at sun.misc.Unsafe.park(Native Method)
> at
> java.util.concurrent.locks.LockSupport.parkUntil(LockSupport.java:351)
> at com.caucho.env.thread.TaskWorker.run(TaskWorker.java:149)
> at java.lang.Thread.run(Thread.java:637)
>
> "resin-thread-launcher" daemon prio=5 tid=101999000 nid=0x117788000
> waiting on condition [117787000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:283)
> at
> com.caucho.env.thread.ThreadPool$ThreadLauncher.startConnection(ThreadPool.java:981)
> at
> com.caucho.env.thread.ThreadPool$ThreadLauncher.run(ThreadPool.java:1003)
>
> "resin-timer" daemon prio=10 tid=10319b800 nid=0x117685000 waiting on
> condition [117684000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> at
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
> at com.caucho.util.Alarm$AlarmThread.run(Alarm.java:567)
>
> "Poller SunPKCS11-Darwin" daemon prio=1 tid=10319a800 nid=0x117582000
> waiting on condition [117581000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at sun.security.pkcs11.SunPKCS11$TokenPoller.run(SunPKCS11.java:692)
> at java.lang.Thread.run(Thread.java:637)
>
> "Low Memory Detector" daemon prio=5 tid=103091000 nid=0x117190000
> runnable [00000000]
> java.lang.Thread.State: RUNNABLE
>
> "CompilerThread1" daemon prio=9 tid=101819800 nid=0x11708d000 waiting
> on condition [00000000]
> java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=9 tid=101819000 nid=0x116f8a000 waiting
> on condition [00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=9 tid=101818000 nid=0x116e87000
> waiting on condition [00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Surrogate Locker Thread (CMS)" daemon prio=5 tid=101817800
> nid=0x116d84000 waiting on condition [00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Finalizer" daemon prio=8 tid=101801800 nid=0x116a0f000 in
> Object.wait() [116a0e000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <107cf3c38> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
> - locked <107cf3c38> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
> at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>
> "Reference Handler" daemon prio=10 tid=101801000 nid=0x11690c000 in
> Object.wait() [11690b000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <107cf0860> (a java.lang.ref.Reference$Lock)
> at java.lang.Object.wait(Object.java:485)
> at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> - locked <107cf0860> (a java.lang.ref.Reference$Lock)
>
> "main" prio=5 tid=103000800 nid=0x100501000 in Object.wait() [100500000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <10809c708> (a com.caucho.boot.ResinBoot)
> at com.caucho.boot.ResinBoot.main(ResinBoot.java:324)
> - locked <10809c708> (a com.caucho.boot.ResinBoot)
>
> "VM Thread" prio=9 tid=103089800 nid=0x116809000 runnable
>
> "Gang worker#0 (Parallel GC Threads)" prio=9 tid=103002000
> nid=0x102201000 runnable
>
> "Gang worker#1 (Parallel GC Threads)" prio=9 tid=103002800
> nid=0x102304000 runnable
>
> "Concurrent Mark-Sweep GC Thread" prio=9 tid=103042000 nid=0x116511000
> runnable
> "VM Periodic Task Thread" prio=10 tid=103092800 nid=0x117293000
> waiting on condition
>
> "Exception Catcher Thread" prio=10 tid=103001800 nid=0x10171b000 runnable
> JNI global references: 975
>
> Heap
> par new generation total 19136K, used 7024K [106810000, 107cd0000,
> 107cd0000)
> eden space 17024K, 28% used [106810000, 106cdc108, 1078b0000)
> from space 2112K, 100% used [1078b0000, 107ac0000, 107ac0000)
> to space 2112K, 0% used [107ac0000, 107ac0000, 107cd0000)
> concurrent mark-sweep generation total 63872K, used 2737K [107cd0000,
> 10bb30000, 10e610000)
> concurrent-mark-sweep perm gen total 21248K, used 14067K [10e610000,
> 10fad0000, 113a10000)
>
>
>
>
> On Tue, Jul 20, 2010 at 4:42 PM, Scott Ferguson <f...@caucho.com> wrote:
>
>> Jeff Schnitzer wrote:
>>
>>> By the way, I was able to work past the lazy-init issue (presumably)
>>> by using this block instead:
>>>
>>> <cfg:MessageBeanConfig>
>>> <cfg:class>test.DeliveryListener</cfg:class>
>>> <cfg:destination>#{delivery}</cfg:destination>
>>> </cfg:MessageBeanConfig>
>>>
>>> However, enqueueing a message doesn't produce calls on my Listener.
>>> It seems to produce some sort of spin-loop inside Resin.
>>>
>>>
>> Try adding a <ee:Startup/> or <resin:Service/>. Otherwise the bean will
>> never get instantiated. It shouldn't spin, though.
>>
>> Although, this is a pretty twisted way of working around the issue :)
>>
>> -- Scott
>>
>>> Jeff
>>>
>>> On Tue, Jul 20, 2010 at 1:17 PM, Jeff Schnitzer <j...@infohazard.org> wrote:
>>>
>>>
>>>> On Tue, Jul 20, 2010 at 12:21 PM, Scott Ferguson <f...@caucho.com> wrote:
>>>>
>>>>
>>>>> Thanks. It's a timing issue in CanDI. The jms:FileQueue was added to a
>>>>> lazy-init which wasn't being evaluated when the #{delivery} was
>>>>> processed. The fix will be in the next snapshot.
>>>>>
>>>>>
>>>> Cool. If you get to a point where this is checked into Resin trunk,
>>>> I'd love to help you test it :-)
>>>>
>>>> Jeff
>>>>
>>>>
>>>>
>>> _______________________________________________
>>> resin-interest mailing list
>>> resin-interest@caucho.com
>>> http://maillist.caucho.com/mailman/listinfo/resin-interest
>>>
>>>
>>
>> _______________________________________________
>> resin-interest mailing list
>> resin-interest@caucho.com
>> http://maillist.caucho.com/mailman/listinfo/resin-interest
>>
>>
>
>
> _______________________________________________
> resin-interest mailing list
> resin-interest@caucho.com
> http://maillist.caucho.com/mailman/listinfo/resin-interest
>
_______________________________________________
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
