[QFJ-458] ConcurrentModificationException raised from quickfix.Session.nextQueued Created: 13/Jul/09  Updated: 15/Nov/12  Resolved: 06/Apr/10

Status: Closed
Project: QuickFIX/J
Component/s: Engine
Affects Version/s: 1.4.0
Fix Version/s: 1.5.0

Type: Bug Priority: Major
Reporter: Steve Borrer Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: None
Environment:

Operating system: Linux tradera2 2.6.24-23-server #1 SMP Thu Nov 27 18:45:02 UTC 2008 x86_64 GNU/Linux
java version "1.6.0_14"
16 GB RAM



 Description   

The issue occurred after I had just restarted my qfj initiator FIX engine:-

15:12:12 INFO: Socket option: SocketSynchronousWriteTimeout=30000
15:12:12 Jul 13, 2009 3:12:11 PM quickfix.mina.initiator.InitiatorIoHandler sessionCreated
15:12:12 INFO: MINA session created: /127.0.0.1:53335
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Initiated logon request
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Logon contains ResetSeqNumFlag=Y, resetting sequence numbers to 1
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Received logon request
15:12:12 20090713-15:12:12 20090713-03:12:12 DEBUG - Session logged on: FIX.4.2:NONAME->SIMULA
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 2 but received 3[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Sent ResendRequest FROM: 2 TO: 0
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 2 but received 4[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 2 but received 5[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 2 but received 6[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 7[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 8[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 9[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - null
15:12:12 [[00;31m^Gjava.util.ConcurrentModificationException[[00m
15:12:12 at java.util.LinkedHashMap$LinkedHashIterator.nextEntry(LinkedHashMap.java:373)
15:12:12 at java.util.LinkedHashMap$KeyIterator.next(LinkedHashMap.java:384)
15:12:12 at java.util.AbstractCollection.toString(AbstractCollection.java:421)
15:12:12 at java.lang.String.valueOf(String.java:2826)
15:12:12 at java.lang.StringBuffer.append(StringBuffer.java:219)
15:12:12 at quickfix.Session.nextQueued(Session.java:1634)
15:12:12 at quickfix.Session.nextQueued(Session.java:1624)
15:12:12 at quickfix.Session.next(Session.java:851)
15:12:12 at quickfix.mina.SingleThreadedEventHandlingStrategy$SessionMessageEvent.processMessage(SingleThreadedEventHandlingStrategy.java:107)
15:12:12 at quickfix.mina.SingleThreadedEventHandlingStrategy.block(SingleThreadedEventHandlingStrategy.java:70)
15:12:12 at quickfix.mina.SingleThreadedEventHandlingStrategy$1.run(SingleThreadedEventHandlingStrategy.java:87)
15:12:12 at java.lang.Thread.run(Thread.java:619)
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 10[[00m
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 11[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 12[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 [[00;31m^G20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - MsgSeqNum too high, expecting 3 but received 13[[00m
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Already sent ResendRequest FROM: 2 TO: 2. Not sending another.
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - ResendRequest for messages FROM 2 TO 2 has been satisfied.
15:12:12 20090713-15:12:12 EVENT [FIX.4.2:NONAME->SIMULA] - Processing queued message: 4, pending: [5, 6, 7, 8, 9, 10, 11, 12, 13]

The log from the FIX acceptor test harness also built with QFJ1.4.0 is :-

[[0034m15:12:11[[37m 20090713-15:12:11 EVENT [FIX.4.2:SIMULA->NONAME] - Session FIX.4.2:SIMULA->NONAME schedule is daily, 22:00:00 UTC - 21:30:00 UTC (daily, 23:00:00 BST - 22:30:00 BST)
[[0034m15:12:11[[37m 20090713-15:12:11 EVENT [FIX.4.2:SIMULA->NONAME] - Created session: FIX.4.2:SIMULA->NONAME
[[0034m15:12:11[[37m Jul 13, 2009 3:12:11 PM quickfix.mina.NetworkingOptions logOption
[[0034m15:12:11[[37m INFO: Socket option: SocketTcpNoDelay=true
[[0034m15:12:11[[37m Jul 13, 2009 3:12:11 PM quickfix.mina.NetworkingOptions logOption
[[0034m15:12:11[[37m INFO: Socket option: SocketSynchronousWrites=false
[[0034m15:12:11[[37m Jul 13, 2009 3:12:11 PM quickfix.mina.NetworkingOptions logOption
[[0034m15:12:11[[37m INFO: Socket option: SocketSynchronousWriteTimeout=30000
[[0034m15:12:11[[37m Jul 13, 2009 3:12:11 PM quickfix.mina.acceptor.AbstractSocketAcceptor startAcceptingConnections
[[0034m15:12:11[[37m INFO: Listening for connections at 0.0.0.0/0.0.0.0:9876
[[0034m15:12:12[[37m Jul 13, 2009 3:12:11 PM quickfix.mina.acceptor.AcceptorIoHandler sessionCreated
[[0034m15:12:12[[37m INFO: MINA session created: /127.0.0.1:53335
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Accepting session FIX.4.2:SIMULA->NONAME from /127.0.0.1:53335
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Acceptor heartbeat set to 30 seconds
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Logon contains ResetSeqNumFlag=Y, resetting sequence numbers to 1
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Received logon request
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Responding to logon request
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Received ResendRequest FROM: 2 TO: infinity
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Resending Message: 2
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Resending Message: 3
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Resending Message: 4
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Resending Message: 5
[[0034m15:12:12[[37m 20090713-15:12:12 EVENT [FIX.4.2:SIMULA->NONAME] - Resending Message: 6


Generated at Mon May 20 08:17:58 UTC 2024 using JIRA 7.5.2#75007-sha1:9f5725bb824792b3230a5d8716f0c13e296a3cae.