Uploaded image for project: 'QuickFIX/J'
  1. QuickFIX/J
  2. QFJ-433

Session can deadlock on responderSync and reduced concurrency

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Default
    • Resolution: Fixed
    • Affects Version/s: 1.4.0
    • Fix Version/s: None
    • Component/s: Engine
    • Labels:
      None
    • Environment:
      Windows Java 1.6

      Description

      Because Session is using a String literal as a lock, the scope of this lock is not per Session instance

      private String responderSync = "SessionResponderSync";
      // @GuardedBy(responderSync)
      private Responder responder;

      As well as reducing concurrency it caused my app to deadlock, because the vm will intern "SessionResponderSync". I suggest changing this to

      private String responderSync = new String("SessionResponderSync");

      My deadlock was probably caused because I was trying a combination of

      1) synchronous writes on both the acceptor and initiator
      2) both the acceptor and initiator in the same vm process
      3) switching out the LinkedBlockingQueue in the SingleThreadedEventHandlingStrategy with a bounded ArrayBlockingQueue

      Here is my stack trace if it helps:

      SocketConnectorIoProcessor-0.0@1168 daemon, priority=5, in group 'main', status: 'WAIT'
      at sun.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1,925)
      at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:252)
      at quickfix.mina.SingleThreadedEventHandlingStrategy.onMessage(SingleThreadedEventHandlingStrategy.java:47)
      at quickfix.mina.initiator.InitiatorIoHandler.processMessage(InitiatorIoHandler.java:54)
      at quickfix.mina.AbstractIoHandler.messageReceived(AbstractIoHandler.java:113)
      at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
      at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
      at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:58)
      at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:180)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
      at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
      at org.apache.mina.common.support.AbstractIoFilterChain$HeadFilter.messageReceived(AbstractIoFilterChain.java:499)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.fireMessageReceived(AbstractIoFilterChain.java:293)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:228)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:198)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProcessor.java:45)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:485)
      at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
      at java.lang.Thread.run(Thread.java:619)

      SocketAcceptorIoProcessor-0.0@1170, priority=5, in group 'main', status: 'WAIT'
      at sun.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1,925)
      at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:252)
      at quickfix.mina.SingleThreadedEventHandlingStrategy.onMessage(SingleThreadedEventHandlingStrategy.java:47)
      at quickfix.mina.acceptor.AcceptorIoHandler.processMessage(AcceptorIoHandler.java:97)
      at quickfix.mina.AbstractIoHandler.messageReceived(AbstractIoHandler.java:113)
      at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
      at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
      at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:58)
      at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:180)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
      at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
      at org.apache.mina.common.support.AbstractIoFilterChain$HeadFilter.messageReceived(AbstractIoFilterChain.java:499)
      at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
      at org.apache.mina.common.support.AbstractIoFilterChain.fireMessageReceived(AbstractIoFilterChain.java:293)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:228)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:198)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProcessor.java:45)
      at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:485)
      at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
      at java.lang.Thread.run(Thread.java:619)

      SocketConnector-0@1154 daemon, priority=5, in group 'main', status: 'RUNNING'
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(WindowsSelectorImpl.java:-1)
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:274)
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:256)
      at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:137)
      at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
      at org.apache.mina.transport.socket.nio.SocketConnector$Worker.run(SocketConnector.java:378)
      at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
      at java.lang.Thread.run(Thread.java:619)

      QFJ Message Processor@1284 daemon, priority=5, in group 'main', status: 'MONITOR'
      waiting for main@1
      at quickfix.Session.getResponder(Session.java:382)
      at quickfix.Session.hasResponder(Session.java:393)
      at quickfix.Session.next(Session.java:1,417)
      at quickfix.Session.next(Session.java:853)
      at quickfix.mina.SingleThreadedEventHandlingStrategy$SessionMessageEvent.processMessage(SingleThreadedEventHandlingStrategy.java:107)
      at quickfix.mina.SingleThreadedEventHandlingStrategy.block(SingleThreadedEventHandlingStrategy.java:70)
      at quickfix.mina.SingleThreadedEventHandlingStrategy$1.run(SingleThreadedEventHandlingStrategy.java:87)
      at java.lang.Thread.run(Thread.java:619)

      QFJ Message Processor@1236 daemon, priority=5, in group 'main', status: 'MONITOR'
      waiting for main@1
      at quickfix.Session.getResponder(Session.java:382)
      at quickfix.Session.hasResponder(Session.java:393)
      at quickfix.Session.next(Session.java:1,417)
      at quickfix.Session.next(Session.java:853)
      at quickfix.mina.SingleThreadedEventHandlingStrategy$SessionMessageEvent.processMessage(SingleThreadedEventHandlingStrategy.java:107)
      at quickfix.mina.SingleThreadedEventHandlingStrategy.block(SingleThreadedEventHandlingStrategy.java:70)
      at quickfix.mina.SingleThreadedEventHandlingStrategy$1.run(SingleThreadedEventHandlingStrategy.java:87)
      at java.lang.Thread.run(Thread.java:619)

      SocketAcceptor-0@1105, priority=5, in group 'main', status: 'RUNNING'
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(WindowsSelectorImpl.java:-1)
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:274)
      at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:256)
      at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:137)
      at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84)
      at org.apache.mina.transport.socket.nio.SocketAcceptor$Worker.run(SocketAcceptor.java:220)
      at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
      at java.lang.Thread.run(Thread.java:619)

      QFJ Timer@1141 daemon, priority=5, in group 'main', status: 'MONITOR'
      waiting for main@1
      at quickfix.Session.getResponder(Session.java:382)
      at quickfix.Session.hasResponder(Session.java:393)
      at quickfix.Session.next(Session.java:1,417)
      at quickfix.mina.SessionConnector$SessionTimerTask.run(SessionConnector.java:248)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
      at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      at java.lang.Thread.run(Thread.java:619)

      OrderBook-testExchange-EURUSD-work-1@733, priority=5, in group 'main', status: 'MONITOR'
      waiting for main@1
      at quickfix.Session.send(Session.java:1,856)
      at quickfix.Session.sendRaw(Session.java:1,803)
      at quickfix.Session.send(Session.java:1,850)
      at quickfix.Session.sendToTarget(Session.java:504)
      ... my stack

      main@1, priority=5, in group 'main', status: 'WAIT'
      blocks QFJ Message Processor@1284
      blocks QFJ Message Processor@1236
      blocks QFJ Timer@1141
      blocks OrderBook-testExchange-EURUSD-work-1@733
      at java.lang.Object.wait(Object.java:-1)
      at org.apache.mina.common.support.DefaultIoFuture.await0(DefaultIoFuture.java:121)
      at org.apache.mina.common.support.DefaultIoFuture.awaitUninterruptibly(DefaultIoFuture.java:100)
      at org.apache.mina.common.support.DefaultIoFuture.join(DefaultIoFuture.java:79)
      at quickfix.mina.IoSessionResponder.send(IoSessionResponder.java:50)
      at quickfix.Session.send(Session.java:1,861)
      at quickfix.Session.sendRaw(Session.java:1,803)
      at quickfix.Session.send(Session.java:1,850)
      at quickfix.Session.sendToTarget(Session.java:504)
      ... my stack

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                sekhonp Parwinder Sekhon
              • Votes:
                0 Vote for this issue
                Watchers:
                0 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: