[ https://issues.apache.org/jira/browse/QPID-7253?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall reassigned QPID-7253: -------------------------------- Assignee: Keith Wall > [Java Client 0-10] Application allowed to create new JMS session whilst > failover is in progress > ----------------------------------------------------------------------------------------------- > > Key: QPID-7253 > URL: https://issues.apache.org/jira/browse/QPID-7253 > Project: Qpid > Issue Type: Bug > Components: Java Client > Affects Versions: 0.30, 0.32, qpid-java-6.0, qpid-java-6.0.2 > Reporter: Keith Wall > Assignee: Keith Wall > Fix For: qpid-java-6.0.3, qpid-java-6.1 > > > Unlike the 0-8 path, creating a JMS session {{Connection#createSession()}} > does not take the failover mutex. This means that an application's call to > createSession does not block whilst failover is in flight. This gives rise > to a race between application's creation of the new session and the > re-subscription of the existing sessions. In an unlucky case, this may cause > the client to try and attach the same session twice. This will be rejected > by the Broker with a SESSION_BUSY. > Following annotated log excerpt is from 6.0.2. > {noformat} > # Failover has just reconnected an application with existing JMS sessions, > but failover is not yet 'finished' > 2016-05-04 17:31:26,778 DEBUG [com/192.168.0.1:18575] [ > Connection] RECV: [conn:eb35720] ch=0 ConnectionOpenOk(knownHosts=[]) > 2016-05-04 17:31:26,779 INFO [com/192.168.0.1:18575] [ > AMQConnection] Connection 1 now connected from /192.168.0.2:48956 to > myhost.example.com/192.168.0.1:18 > 575 > # Application thread gets in and creates a new session > 2016-05-04 17:31:26,779 DEBUG [ app-listener-thread:01] [ > Connection] SEND: [conn:eb35720] ch=2 > SessionAttach(name="916a6c14-069f-4cd0-ba8b-dde789766864") > 2016-05-04 17:31:26,779 DEBUG [ app-listener-thread:01] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,779 DEBUG [ app-listener-thread:01] [ > Connection] SEND: [conn:eb35720] ch=2 > SessionRequestTimeout(timeout=0) > # Failover begins to 'rewire' the existing JMS objects > 2016-05-04 17:31:26,780 INFO [com/192.168.0.1:18575] [ > AMQConnectionDelegate_0_10] Resuming connection > 2016-05-04 17:31:26,780 DEBUG [ app-listener-thread:01] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 > SessionAttach(name="edd4afef-052f-4dfc-8af0-ca96a887977c") > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 SessionRequestTimeout(timeout=0) > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 > SessionCommandPoint(commandId=12383, commandOffset=0) > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 id=12383 ExecutionSync() > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 > SessionCommandPoint(commandId=12384, commandOffset=0) > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 SessionFlush(completed=true) > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=3 id=12384 TxSelect() > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > # DEFECT Failover treats the application's new session as if it were an > existing one > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=4 > SessionAttach(name="916a6c14-069f-4cd0-ba8b-dde789766864") > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,781 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=4 SessionRequestTimeout(timeout=0) > 2016-05-04 17:31:26,782 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,782 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=4 SessionCommandPoint(commandId=0, > commandOffset=0) > 2016-05-04 17:31:26,782 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > 2016-05-04 17:31:26,782 DEBUG [com/192.168.0.1:18575] [ > Connection] SEND: [conn:eb35720] ch=4 SessionFlush(completed=true) > 2016-05-04 17:31:26,782 DEBUG [com/192.168.0.1:18575] [ > Connection] FLUSH: [conn:eb35720] > ... > 2016-05-04 17:31:26,782 INFO [com/192.168.0.1:18575] [ > AMQConnectionDelegate_0_10] Resubscribing sessions = > [org.apache.qpid.client.AMQSession_0_10@2a3998ec, org.apache.qpid.client.A > MQSession_0_10@4b230bb3] sessions.size=2 > 2016-05-04 17:31:26,783 DEBUG [com/192.168.0.1:18575] [ > AMQSession] Resubscribing producers = [] producers.size=0 > … > # Broker rejects the attempt to attach the same session to the second > transport > 2016-05-04 17:31:26,798 DEBUG [com/192.168.0.1:18575] [ > Connection] RECV: [conn:eb35720] ch=4 > SessionDetached(name="916a6c14-069f-4cd0-ba8b-dde789766864", code=SESSION > _BUSY) > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332) --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org For additional commands, e-mail: dev-h...@qpid.apache.org