Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.6.1
    • Fix Version/s: 1.6.x, 1.7, 2.x
    • Component/s: None
    • Labels:
      None
    • Environment:
      Solaris 1.5.0_08-b03

      Description

      I cannot reproduce this at will, and have only seen it the once but if someone more familiar with the code than me could take a look that would be appreciated. I have several threads calling Template.merge, and somehow here they got locked up somewhere and caused a 100% cpu loop hang between them. Here's a thread dump after several hours of getting nowhere.

      Full thread dump Java HotSpot(TM) Server VM (1.5.0_08-b03 mixed mode):

      "RMI ConnectionExpiration-[162.11.2.155:46163]" daemon prio=10 tid=0x01a58838 nid=0x91 waiting on condition [0xaf701000..0xaf701888]
      at java.lang.Thread.sleep(Native Method)
      at sun.rmi.transport.tcp.TCPChannel$Reaper.run(TCPChannel.java:446)
      at java.lang.Thread.run(Thread.java:595)

      "GC Daemon" daemon prio=2 tid=0x018972f8 nid=0x33 in Object.wait() [0xaf801000..0xaf801988]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb92ae8b0> (a sun.misc.GC$LatencyLock)
        at sun.misc.GC$Daemon.run(GC.java:100)
      • locked <0xb92ae8b0> (a sun.misc.GC$LatencyLock)

      "RMI RenewClean-[162.11.2.155:46163]" daemon prio=10 tid=0x01d83578 nid=0x32 in Object.wait() [0xaf901000..0xaf901a08]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb92ae980> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
      • locked <0xb92ae980> (a java.lang.ref.ReferenceQueue$Lock)
        at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:501)
        at java.lang.Thread.run(Thread.java:595)

      "pool-1-thread-3" prio=10 tid=0x01d64fa0 nid=0x31 waiting on condition [0xafa01000..0xafa01888]
      at sun.misc.Unsafe.park(Native Method)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1767)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
      at java.lang.Thread.run(Thread.java:595)

      "pool-1-thread-2" prio=10 tid=0x00f7edb0 nid=0x30 waiting on condition [0xafb01000..0xafb01908]
      at sun.misc.Unsafe.park(Native Method)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1767)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
      at java.lang.Thread.run(Thread.java:595)

      "pool-1-thread-1" prio=10 tid=0x020574a8 nid=0x2f waiting on condition [0xafc01000..0xafc01788]
      at sun.misc.Unsafe.park(Native Method)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1767)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-10" prio=10 tid=0x01da9d38 nid=0x2e runnable [0xafcff000..0xafd01808]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-9" prio=10 tid=0x0064b100 nid=0x2d runnable [0xafdff000..0xafe01688]
      at java.util.HashMap.put(HashMap.java:420)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:271)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-8" prio=10 tid=0x0064b7b0 nid=0x2c runnable [0xafeff000..0xaff01708]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-7" prio=10 tid=0x01d2d1d8 nid=0x2b runnable [0xb0000000..0xb0001988]
      at java.util.HashMap.put(HashMap.java:420)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:271)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-6" prio=10 tid=0x0153a960 nid=0x2a runnable [0xb0100000..0xb0101a08]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-5" prio=10 tid=0x00d8d1d0 nid=0x29 runnable [0xb01ff000..0xb0201888]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-4" prio=10 tid=0x00f30d30 nid=0x28 runnable [0xb0300000..0xb0301908]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-3" prio=10 tid=0x00b35ed0 nid=0x27 runnable [0xb03ff000..0xb0401788]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-2" prio=10 tid=0x006ca6d0 nid=0x26 runnable [0xb04ff000..0xb0501808]
      at java.util.HashMap.get(HashMap.java:346)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "pool-2-thread-1" prio=10 tid=0x007b0d88 nid=0x25 runnable [0xb0bff000..0xb0c01688]
      at java.util.HashMap.put(HashMap.java:420)
      at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:271)
      at org.apache.velocity.util.introspection.ClassMap.findMethod(ClassMap.java:102)
      at org.apache.velocity.util.introspection.IntrospectorBase.getMethod(IntrospectorBase.java:105)
      at org.apache.velocity.util.introspection.Introspector.getMethod(Introspector.java:94)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.discover(PropertyExecutor.java:118)
      at org.apache.velocity.runtime.parser.node.PropertyExecutor.<init>(PropertyExecutor.java:56)
      at org.apache.velocity.util.introspection.UberspectImpl.getPropertyGet(UberspectImpl.java:246)
      at org.apache.velocity.runtime.parser.node.ASTIdentifier.execute(ASTIdentifier.java:148)
      at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:252)
      at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:332)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:212)
      at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:247)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:364)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)
      at com.formicary.financial.model2murex.velocity.VelocityTradeWriter.generateMxml(VelocityTradeWriter.java:149)
      at com.formicary.financial.model2murex.MurexSink.writeTrades(MurexSink.java:63)
      at com.formicary.financial.model2murex.EnhancingMurexSink.writeTrades(EnhancingMurexSink.java:18)
      at com.formicary.financial.oldcode.murexsink.BothMurexSinks.writeTrades(BothMurexSinks.java:46)
      at com.formicary.financial.migration.Migration.migrate(Migration.java:111)
      at com.formicary.financial.migration.Migration.access$100(Migration.java:37)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:313)
      at com.formicary.financial.migration.Migration$MigrationTask.call(Migration.java:280)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
      at java.util.concurrent.FutureTask.run(FutureTask.java:123)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
      at java.lang.Thread.run(Thread.java:595)

      "PoolExecutor" daemon prio=10 tid=0x00861128 nid=0x22 in Object.wait() [0xb0601000..0xb0601a08]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x0085b7d8 nid=0x21 in Object.wait() [0xb0701000..0xb0701888]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x0085b028 nid=0x20 in Object.wait() [0xb0801000..0xb0801908]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x00861ea0 nid=0x1f in Object.wait() [0xb0901000..0xb0901788]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x00648718 nid=0x1e in Object.wait() [0xb0a01000..0xb0a01808]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb81de0e0> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "Timer-1" daemon prio=10 tid=0x009d6520 nid=0x1c in Object.wait() [0xb0b01000..0xb0b01708]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8258028> (a java.util.TaskQueue)
        at java.lang.Object.wait(Object.java:474)
        at java.util.TimerThread.mainLoop(Timer.java:483)
      • locked <0xb8258028> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

      "PoolExecutor" daemon prio=10 tid=0x00a618f0 nid=0x1a in Object.wait() [0xb0d01000..0xb0d01a08]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x0087eef0 nid=0x19 in Object.wait() [0xb0e01000..0xb0e01888]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x00ecd1c8 nid=0x18 in Object.wait() [0xb0f01000..0xb0f01908]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x00eccf60 nid=0x17 in Object.wait() [0xb1001000..0xb1001788]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "PoolExecutor" daemon prio=10 tid=0x00c19ee0 nid=0x16 in Object.wait() [0xb1101000..0xb1101808]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at java.lang.Object.wait(Object.java:474)
        at com.swiftmq.client.thread.ThreadPoolImpl.getNextTask(Unknown Source)
      • locked <0xb8207070> (a com.swiftmq.client.thread.ThreadPoolImpl)
        at com.swiftmq.client.thread.PoolExecutor.run(Unknown Source)

      "Timer-0" daemon prio=10 tid=0x00d64c80 nid=0x15 in Object.wait() [0xb1201000..0xb1201688]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb80a9008> (a java.util.TaskQueue)
        at java.lang.Object.wait(Object.java:474)
        at java.util.TimerThread.mainLoop(Timer.java:483)
      • locked <0xb80a9008> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

      "Low Memory Detector" daemon prio=10 tid=0x001803c0 nid=0x13 runnable [0x00000000..0x00000000]

      "CompilerThread1" daemon prio=10 tid=0x0017f308 nid=0x12 waiting on condition [0x00000000..0xb3980ac4]

      "CompilerThread0" daemon prio=10 tid=0x0017e498 nid=0x11 waiting on condition [0x00000000..0xb3a80894]

      "AdapterThread" daemon prio=10 tid=0x0017d608 nid=0x10 waiting on condition [0x00000000..0x00000000]

      "Signal Dispatcher" daemon prio=10 tid=0x0017c9a8 nid=0xf waiting on condition [0x00000000..0x00000000]

      "Finalizer" daemon prio=10 tid=0x00171b98 nid=0xe in Object.wait() [0xb3d81000..0xb3d81808]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb80114d0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
      • locked <0xb80114d0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

      "Reference Handler" daemon prio=10 tid=0x00171628 nid=0xd in Object.wait() [0xb3e81000..0xb3e81688]
      at java.lang.Object.wait(Native Method)

      • waiting on <0xb800e6f0> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:474)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
      • locked <0xb800e6f0> (a java.lang.ref.Reference$Lock)

      "main" prio=10 tid=0x000385c8 nid=0x1 waiting on condition [0xffbee000..0xffbee8a0]
      at sun.misc.Unsafe.park(Native Method)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1767)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)
      at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:136)
      at com.formicary.financial.migration.Migration.main(Migration.java:201)
      at com.formicary.financial.migration.tools.exotics.KtpfMigrator.call(KtpfMigrator.java:44)
      at com.formicary.financial.migration.tools.exotics.KtpfMigrator.main(KtpfMigrator.java:26)

      "VM Thread" prio=10 tid=0x0016ef68 nid=0xc runnable

      "GC task thread#0 (ParallelGC)" prio=10 tid=0x000b9cf0 nid=0x4 runnable

      "GC task thread#1 (ParallelGC)" prio=10 tid=0x000ba730 nid=0x5 runnable

      "GC task thread#2 (ParallelGC)" prio=10 tid=0x000bb170 nid=0x6 runnable

      "GC task thread#3 (ParallelGC)" prio=10 tid=0x000bbbb0 nid=0x7 runnable

      "GC task thread#4 (ParallelGC)" prio=10 tid=0x000bc5f0 nid=0x8 runnable

      "GC task thread#5 (ParallelGC)" prio=10 tid=0x000bd030 nid=0x9 runnable

      "GC task thread#6 (ParallelGC)" prio=10 tid=0x000bda70 nid=0xa runnable

      "GC task thread#7 (ParallelGC)" prio=10 tid=0x000becb8 nid=0xb runnable

      "VM Periodic Task Thread" prio=10 tid=0x00182050 nid=0x14 waiting on condition

      1. mapfactory.patch
        3 kB
        Nathan Bubna
      2. velocity-1.7-dev.jar
        438 kB
        Nathan Bubna

        Activity

        Hide
        Will Glass-Husain added a comment -

        Note to team:

        There's a classic bug in Sun's implementation of HashMap in which simultaneous calls to get can cause an infinite loop. I've experienced this and the symptons are a similarly bizarre 100% CPU utilization. If you look through the stack trace above you can see this.

        "pool-2-thread-2" prio=10 tid=0x006ca6d0 nid=0x26 runnable [0xb04ff000..0xb0501808]
        at java.util.HashMap.get(HashMap.java:346)
        at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248)

        The solution is to properly synchronize access to get. (or when feasible, use ConcurrentHashMap from JDK 1.5+)

        References:

        http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6423457

        http://lightbody.net/blog/2005/07/hashmapget_can_cause_an_infini.html

        Show
        Will Glass-Husain added a comment - Note to team: There's a classic bug in Sun's implementation of HashMap in which simultaneous calls to get can cause an infinite loop. I've experienced this and the symptons are a similarly bizarre 100% CPU utilization. If you look through the stack trace above you can see this. "pool-2-thread-2" prio=10 tid=0x006ca6d0 nid=0x26 runnable [0xb04ff000..0xb0501808] at java.util.HashMap.get(HashMap.java:346) at org.apache.velocity.util.introspection.ClassMap$MethodCache.get(ClassMap.java:248) The solution is to properly synchronize access to get. (or when feasible, use ConcurrentHashMap from JDK 1.5+) References: http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6423457 http://lightbody.net/blog/2005/07/hashmapget_can_cause_an_infini.html
        Hide
        Nathan Bubna added a comment -

        Icky. We can create that map using our new MapFactory. This will use ConcurrentHashMap if available. If not, it will use a HashTable (assuming null keys aren't needed, in which case it falls back to a synchronized HashMap).

        Show
        Nathan Bubna added a comment - Icky. We can create that map using our new MapFactory. This will use ConcurrentHashMap if available. If not, it will use a HashTable (assuming null keys aren't needed, in which case it falls back to a synchronized HashMap).
        Hide
        Will Glass-Husain added a comment -

        incidentally, as a user who runs servers with heavy load – I'm worried about this one. Mysterious 100% CPI hangups on the server seems dangerous.

        Show
        Will Glass-Husain added a comment - incidentally, as a user who runs servers with heavy load – I'm worried about this one. Mysterious 100% CPI hangups on the server seems dangerous.
        Hide
        Nathan Bubna added a comment -

        Well, i tried for a little while to replicate this, but haven't had any luck. I can change ClassMap (and MethodMap, i suppose) to use MapFactory-created Maps and provide a custom build of 1.7-dev, if someone would like to try that out. Or we could just do this blind and assume that's the right fix.

        Show
        Nathan Bubna added a comment - Well, i tried for a little while to replicate this, but haven't had any luck. I can change ClassMap (and MethodMap, i suppose) to use MapFactory-created Maps and provide a custom build of 1.7-dev, if someone would like to try that out. Or we could just do this blind and assume that's the right fix.
        Hide
        Nathan Bubna added a comment -

        Here's a 1.7-dev build that uses MapFactory to provide concurrency-safe Maps for ClassMap and MethodMap. Also attached is the relevant patch.

        Chris, if you (or someone else) could test this out and confirm the fix, that'd be swell. If you really need a 1.6.x build to test this, let me know.

        Show
        Nathan Bubna added a comment - Here's a 1.7-dev build that uses MapFactory to provide concurrency-safe Maps for ClassMap and MethodMap. Also attached is the relevant patch. Chris, if you (or someone else) could test this out and confirm the fix, that'd be swell. If you really need a 1.6.x build to test this, let me know.
        Hide
        Will Glass-Husain added a comment -

        clever solution.

        Show
        Will Glass-Husain added a comment - clever solution.
        Hide
        Nathan Bubna added a comment -

        I really do think that should solve it. Though confirmation from someone who can reproduce it would be nice...

        Show
        Nathan Bubna added a comment - I really do think that should solve it. Though confirmation from someone who can reproduce it would be nice...
        Hide
        Byron Foster added a comment -

        I tried to reproduce, but didn't have any luck. However I'm using os x, single processor, java 1.5. Lots of things could aggravate this problem.

        But, clearly this is a bug. Multiple threads are accessing (and modifying) a non thread safe object HashMap(). I agree that changing to ConcurrentHashMap at least fixes the threading bug, and I am 99% sure that it is the source of this issue.

        Show
        Byron Foster added a comment - I tried to reproduce, but didn't have any luck. However I'm using os x, single processor, java 1.5. Lots of things could aggravate this problem. But, clearly this is a bug. Multiple threads are accessing (and modifying) a non thread safe object HashMap(). I agree that changing to ConcurrentHashMap at least fixes the threading bug, and I am 99% sure that it is the source of this issue.
        Hide
        Nathan Bubna added a comment -

        Ok, given the utter lack of confirmation and long passage of time, i've decided to just assume that this is indeed fixed and port it to the 1.6.x branch. It will hopefully come out in a 1.6.4 release, eventually.

        Show
        Nathan Bubna added a comment - Ok, given the utter lack of confirmation and long passage of time, i've decided to just assume that this is indeed fixed and port it to the 1.6.x branch. It will hopefully come out in a 1.6.4 release, eventually.

          People

          • Assignee:
            Unassigned
            Reporter:
            Chris Pearson
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development