Hi all, I believe I have come to the bottom of this problem but i am unsure who needs to fix it. What seems to happen is that when using QPID JMS 0.30, two sessions get created, one is the ’transport session’ and the other one is used when i create the durable subscriber which i then detach. When unsubscribe (name) is being called this uses the transport session so a new sender object is created which results in an attach response. When doing the same with qpid 0.32 legacy JMS client, only a single session is created and used throughout. As a result of this, when i call unsubscribe (name), the previous sender object is found in the senders hash with state (remote:local) = CLOSED:ACTIVE. The sender(name) method in session only creates a new sender object if one is not found in the hash OR if one is found but both local and remote state are CLOSED (which is strange because detach frame had closed=false but anyway). As a result it reuses the existing sender and despite me calling attach on it no attach frame is sent.
At a guess the sender (name) method should also create a new sender object if the remote state is CLOSED or the sender object should always send an attach frame if attach has been called. Thoughts? Best Regards, Alex Kritikos Software AG From: "Kritikos, Alex" <alex.kriti...@softwareag.com<mailto:alex.kriti...@softwareag.com>> Subject: Problem with Proton-j 0.9.1 Date: 23 Ιουλίου 2015 - 8:00:51 μ.μ. EEST To: "proton@qpid.apache.org<mailto:proton@qpid.apache.org>" <proton@qpid.apache.org<mailto:proton@qpid.apache.org>> Reply-To: <proton@qpid.apache.org<mailto:proton@qpid.apache.org>> Hi all, We have a broker that uses proton-j 0.9.1 and we execute a test that does a NULL lookup caused by the JMSSession.unsubscribe(name) call. The test passes when using the QPID Proton JMS 0.3.0 but fails when run used the QPID legacy JMS 0.32 with the following error: javax.jms.JMSException: Timeout waiting for attach at org.apache.qpid.amqp_1_0.jms.impl.SessionImpl.unsubscribe(SessionImpl.java:663) The test essentially does the following: 1. Create a durable subscriber 2. Close it (causes detach but no close) 3. Call JMSSession.unsubscribe(name) to delete the durable subscriber state) What appears to be happening is that when the attach frame of step 3 is sent, we call the link.open() method causing a LINK_LOCAL_OPEN proton event, however proton does not send an attach response. This is only when using the legacy JMS client and it looks like there are some differences in the frame traffic (attached below) Could this be a Proton bug? Any help will be greatly appreciated. Regards, Alex Kritikos Software AG Proton client ——————- Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=CONNECTION_INIT, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@3fa05c3d} Thu Jul 23 17:49:06 EEST 2015 ReadPool:1 AMQP>RECV: {Open{ containerId='testTopicDeleteDurableSubscriberState', hostname='localhost', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=CONNECTION_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@3fa05c3d} Thu Jul 23 17:49:06 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=CONNECTION_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@3fa05c3d} Thu Jul 23 17:49:06 EEST 2015 WritePool:4 AMQP>SENT: {Open{ containerId='', hostname='', maxFrameSize=4294967295, channelMax=65535, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:3 AMQP>RECV: {Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=0, outgoingWindow=0, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:3 AMQP>RECV: {Flow{nextIncomingId=null, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=0, handle=null, deliveryCount=null, linkCredit=null, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:3 AMQP>Trace:EventImpl{type=SESSION_INIT, context=org.apache.qpid.proton.engine.impl.SessionImpl@3e755d27} Thu Jul 23 17:49:06 EEST 2015 ReadPool:3 AMQP>Trace:EventImpl{type=SESSION_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@3e755d27} Thu Jul 23 17:49:06 EEST 2015 ReadPool:3 AMQP>Trace:EventImpl{type=SESSION_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@3e755d27} Thu Jul 23 17:49:06 EEST 2015 WritePool:1 AMQP>SENT: {Begin{remoteChannel=0, nextOutgoingId=1, incomingWindow=0, outgoingWindow=0, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 WritePool:1 AMQP>SENT: {Flow{nextIncomingId=1, incomingWindow=2147483647, nextOutgoingId=1, outgoingWindow=0, handle=null, deliveryCount=null, linkCredit=null, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:0 AMQP>RECV: {Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=0, outgoingWindow=0, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:0 AMQP>RECV: {Flow{nextIncomingId=null, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=0, handle=null, deliveryCount=null, linkCredit=null, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:0 AMQP>Trace:EventImpl{type=SESSION_INIT, context=org.apache.qpid.proton.engine.impl.SessionImpl@b36cb7a} Thu Jul 23 17:49:06 EEST 2015 ReadPool:0 AMQP>Trace:EventImpl{type=SESSION_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@b36cb7a} Thu Jul 23 17:49:06 EEST 2015 ReadPool:0 AMQP>Trace:EventImpl{type=SESSION_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@b36cb7a} Thu Jul 23 17:49:06 EEST 2015 WritePool:2 AMQP>SENT: {Begin{remoteChannel=1, nextOutgoingId=1, incomingWindow=0, outgoingWindow=0, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 WritePool:2 AMQP>SENT: {Flow{nextIncomingId=1, incomingWindow=2147483647, nextOutgoingId=1, outgoingWindow=0, handle=null, deliveryCount=null, linkCredit=null, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:4 AMQP>RECV: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='testTopic', durable=UNSETTLED_STATE, expiryPolicy=NEVER, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=copy, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[topic]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_INIT, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 WritePool:6 AMQP>SENT: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=SENDER, sndSettleMode=MIXED, rcvSettleMode=FIRST, source=Source{address='testTopic', durable=UNSETTLED_STATE, expiryPolicy=NEVER, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=copy, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[topic]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>RECV: {Flow{nextIncomingId=1, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=0, handle=0, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=LINK_FLOW, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>RECV: {Detach{handle=0, closed=false, error=null}} Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=LINK_REMOTE_DETACH, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=LINK_LOCAL_DETACH, context=org.apache.qpid.proton.engine.impl.SenderImpl@3a68bc56} Thu Jul 23 17:49:06 EEST 2015 WritePool:1 AMQP>SENT: {Detach{handle=0, closed=false, error=null}} (this is when the unsubscribe(string) call occurs) Thu Jul 23 17:49:50 EEST 2015 ReadPool:5 AMQP>RECV: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=null, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:50 EEST 2015 ReadPool:5 AMQP>Link init Thu Jul 23 17:49:50 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=LINK_INIT, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Thu Jul 23 17:49:50 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=LINK_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Thu Jul 23 17:49:50 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=LINK_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Thu Jul 23 17:49:50 EEST 2015 WritePool:5 AMQP>SENT: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=SENDER, sndSettleMode=MIXED, rcvSettleMode=FIRST, source=Source{address='testTopic', durable=UNSETTLED_STATE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=null}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:49:50 EEST 2015 ReadPool:1 AMQP>RECV: {Detach{handle=0, closed=true, error=null}} Thu Jul 23 17:49:50 EEST 2015 WritePool:2 AMQP>SENT: {Detach{handle=0, closed=true, error=null}} Thu Jul 23 17:49:50 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=LINK_REMOTE_CLOSE, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Thu Jul 23 17:49:50 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=LINK_LOCAL_CLOSE, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Thu Jul 23 17:49:50 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=LINK_FINAL, context=org.apache.qpid.proton.engine.impl.SenderImpl@8a41535} Legacy client ——————- Thu Jul 23 17:36:59 EEST 2015 ReadPool:1 AMQP>Trace:EventImpl{type=CONNECTION_INIT, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@55602519} Thu Jul 23 17:36:59 EEST 2015 ReadPool:3 AMQP>RECV: {Open{ containerId='testTopicDeleteDurableSubscriberState', hostname='null', maxFrameSize=65536, channelMax=255, idleTimeOut=null, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:3 AMQP>Trace:EventImpl{type=CONNECTION_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@55602519} Thu Jul 23 17:36:59 EEST 2015 ReadPool:3 AMQP>Trace:EventImpl{type=CONNECTION_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.ConnectionImpl@55602519} Thu Jul 23 17:36:59 EEST 2015 WritePool:1 AMQP>SENT: {Open{ containerId='', hostname='', maxFrameSize=4294967295, channelMax=65535, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:5 AMQP>RECV: {Begin{remoteChannel=null, nextOutgoingId=0, incomingWindow=2048, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=SESSION_INIT, context=org.apache.qpid.proton.engine.impl.SessionImpl@6100bf59} Thu Jul 23 17:36:59 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=SESSION_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@6100bf59} Thu Jul 23 17:36:59 EEST 2015 ReadPool:5 AMQP>Trace:EventImpl{type=SESSION_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SessionImpl@6100bf59} Thu Jul 23 17:36:59 EEST 2015 WritePool:4 AMQP>SENT: {Begin{remoteChannel=0, nextOutgoingId=1, incomingWindow=0, outgoingWindow=0, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 WritePool:4 AMQP>SENT: {Flow{nextIncomingId=0, incomingWindow=2147483647, nextOutgoingId=1, outgoingWindow=0, handle=null, deliveryCount=null, linkCredit=null, available=null, drain=false, echo=false, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>RECV: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='topic://testTopic', durable=UNSETTLED_STATE, expiryPolicy=NEVER, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=copy, filter=null, defaultOutcome=null, outcomes=null, capabilities=null}, target=Target{address='8e653a67-7b12-4fcc-a7e0-7f836c103928', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Link init Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_INIT, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:36:59 EEST 2015 WritePool:2 AMQP>SENT: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=SENDER, sndSettleMode=MIXED, rcvSettleMode=FIRST, source=Source{address='topic://testTopic', durable=UNSETTLED_STATE, expiryPolicy=NEVER, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=copy, filter=null, defaultOutcome=null, outcomes=null, capabilities=null}, target=Target{address='8e653a67-7b12-4fcc-a7e0-7f836c103928', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>RECV: {Detach{handle=0, closed=false, error=null}} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_REMOTE_DETACH, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:36:59 EEST 2015 ReadPool:4 AMQP>Trace:EventImpl{type=LINK_LOCAL_DETACH, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:36:59 EEST 2015 WritePool:1 AMQP>SENT: {Detach{handle=0, closed=false, error=null}} (this is when the unsubscribe(string) call occurs) Thu Jul 23 17:37:21 EEST 2015 ReadPool:2 AMQP>RECV: {Attach{name='testTopicDeleteDurableSubscriberState', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=null, target=Target{address='fe08f28a-f8ad-4031-8e63-a5759176f8da', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}} Thu Jul 23 17:37:21 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=LINK_REMOTE_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} Thu Jul 23 17:37:21 EEST 2015 ReadPool:2 AMQP>Trace:EventImpl{type=LINK_LOCAL_OPEN, context=org.apache.qpid.proton.engine.impl.SenderImpl@78129dcf} This communication contains information which is confidential and may also be privileged. It is for the exclusive use of the intended recipient(s). If you are not the intended recipient(s), please note that any distribution, copying, or use of this communication or the information in it, is strictly prohibited. If you have received this communication in error please notify us by e-mail and then delete the e-mail and any copies of it. Software AG (UK) Limited Registered in England & Wales 1310740 - http://www.softwareag.com/uk This communication contains information which is confidential and may also be privileged. It is for the exclusive use of the intended recipient(s). If you are not the intended recipient(s), please note that any distribution, copying, or use of this communication or the information in it, is strictly prohibited. If you have received this communication in error please notify us by e-mail and then delete the e-mail and any copies of it. Software AG (UK) Limited Registered in England & Wales 1310740 - http://www.softwareag.com/uk
