Gordon Sim created DISPATCH-595:
-----------------------------------

             Summary: dispositions propagated after link detach on link route
                 Key: DISPATCH-595
                 URL: https://issues.apache.org/jira/browse/DISPATCH-595
             Project: Qpid Dispatch
          Issue Type: Bug
    Affects Versions: 0.8.0
            Reporter: Gordon Sim


We have a subscriber that is link routed through router to a broker. If the 
subscriber detaches immediately after accepting a message, the acknowledgement 
of that message is only relaye dto the broker after the relaying of the link 
detach. This means the message is left on the queue, though the subscriber had 
explicitly accepted it.

{noformat}
Tue Dec 13 17:43:52 2016 AGENT (warning) routerId is deprecated, use id instead
Tue Dec 13 17:43:52 2016 SERVER (warning) HTTP support is not available
Tue Dec 13 17:43:52 2016 SERVER (info) Container Name: Router.A
Tue Dec 13 17:43:52 2016 ROUTER (info) Router started in Standalone mode
Tue Dec 13 17:43:52 2016 ROUTER_CORE (info) Router Core thread running. 
0/Router.A
Tue Dec 13 17:43:52 2016 ROUTER_CORE (info) In-process subscription 
M/$management
Tue Dec 13 17:43:52 2016 AGENT (info) Activating management agent on 
$_management_internal
Tue Dec 13 17:43:52 2016 ROUTER_CORE (info) In-process subscription 
L/$management
Tue Dec 13 17:43:52 2016 ROUTER_CORE (info) In-process subscription 
L/$_management_internal
Tue Dec 13 17:43:52 2016 CONN_MGR (info) Configured Listener: 0.0.0.0:5672 
proto=any, role=normal
Tue Dec 13 17:43:52 2016 CONN_MGR (info) Configured Connector: 0.0.0.0:5673 
proto=any, role=route-container 
Tue Dec 13 17:43:52 2016 POLICY (info) Policy configured maxConnections: 65535, 
policyDir: '', access rules enabled: 'false'
Tue Dec 13 17:43:52 2016 POLICY (info) Policy fallback defaultVhost is defined: 
'$default'
Tue Dec 13 17:43:52 2016 SERVER (info) Operational, 4 Threads Running
[0x7f4764006fd0]:  -> SASL
[0x7f4764006fd0]:  <- SASL
[0x7f4764006fd0]:0 <- @sasl-mechanisms(64) 
[sasl-server-mechanisms=@PN_SYMBOL[:PLAIN, :ANONYMOUS]]
[0x7f4764006fd0]:0 -> @sasl-init(65) [mechanism=:ANONYMOUS, 
initial-response=b"[email protected]"]
[0x7f4764006fd0]:0 <- @sasl-outcome(68) [code=0]
[0x7f4764006fd0]:  -> AMQP
[0x7f4764006fd0]:0 -> @open(16) [container-id="Router.A", hostname="0.0.0.0", 
max-frame-size=16384, channel-max=32767, idle-time-out=8000, 
offered-capabilities=:"ANONYMOUS-RELAY", 
properties={:product="qpid-dispatch-router", :version="0.8.0"}]
[0x7f4764006fd0]:  <- AMQP
[0x7f4764006fd0]:0 <- @open(16) [container-id="0.0.0.0", 
max-frame-size=4294967295, channel-max=65535, idle-time-out=30000, 
offered-capabilities=@PN_SYMBOL[:"sole-connection-for-container", 
:"DELAYED_DELIVERY"], properties={:product="apache-activemq-artemis", 
:version="1.6.0-SNAPSHOT"}]
Tue Dec 13 17:43:53 2016 ROUTER_CORE (info) Link Route Activated 'linkRoute/0' 
on connection redirect
Tue Dec 13 17:43:53 2016 ROUTER_CORE (info) Link Route Activated 'linkRoute/1' 
on connection redirect
[0x7f4760006b70]:  <- SASL
[0x7f4760006b70]:  -> SASL
[0x7f4760006b70]:0 -> @sasl-mechanisms(64) 
[sasl-server-mechanisms=@PN_SYMBOL[:ANONYMOUS, :"DIGEST-MD5", :PLAIN]]
[0x7f4760006b70]:0 <- @sasl-init(65) [mechanism=:ANONYMOUS, 
initial-response=b"[email protected]"]
[0x7f4760006b70]:0 -> @sasl-outcome(68) [code=0]
[0x7f4760006b70]:  <- AMQP
[0x7f4760006b70]:0 <- @open(16) [container-id="myclient", hostname="localhost", 
channel-max=32767]
[0x7f4760006b70]:0 <- @begin(17) [next-outgoing-id=0, 
incoming-window=2147483647, outgoing-window=2147483647]
[0x7f4760006b70]:0 <- @attach(18) [name="mysubscription", handle=0, role=true, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="test", 
durable=2, expiry-policy=:never, timeout=0, dynamic=false, 
capabilities=:topic], target=@target(41) [durable=0, timeout=0, dynamic=false], 
initial-delivery-count=0]
[0x7f4760006b70]:0 <- @flow(19) [incoming-window=2147483647, 
next-outgoing-id=0, outgoing-window=2147483647, handle=0, delivery-count=0, 
link-credit=10, drain=false]
[0x7f4760006b70]:  -> AMQP
[0x7f4760006b70]:0 -> @open(16) [container-id="Router.A", max-frame-size=16384, 
channel-max=32767, idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY", 
properties={:product="qpid-dispatch-router", :version="0.8.0"}]
[0x7f4760006b70]:0 -> @begin(17) [remote-channel=0, next-outgoing-id=0, 
incoming-window=100, outgoing-window=2147483647]
[0x7f4764006fd0]:0 -> @begin(17) [next-outgoing-id=0, incoming-window=100, 
outgoing-window=2147483647]
[0x7f4764006fd0]:0 -> @attach(18) [name="mysubscription", handle=0, role=true, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="test", 
durable=2, expiry-policy=:never, timeout=0, dynamic=false, 
capabilities=:topic], target=@target(41) [durable=0, timeout=0, dynamic=false], 
initial-delivery-count=0]
[0x7f4764006fd0]:0 -> @flow(19) [incoming-window=100, next-outgoing-id=0, 
outgoing-window=2147483647, handle=0, delivery-count=0, link-credit=10, 
drain=false]
[0x7f4764006fd0]:0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, 
incoming-window=2147483647, outgoing-window=2147483647, handle-max=65535]
[0x7f4764006fd0]:0 <- @attach(18) [name="mysubscription", handle=0, role=false, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="test", 
durable=2, expiry-policy=:never, timeout=0, dynamic=false, 
capabilities=@PN_SYMBOL[:topic]], target=@target(41) [], 
incomplete-unsettled=false, initial-delivery-count=0]
[0x7f4760006b70]:0 -> @attach(18) [name="mysubscription", handle=0, role=false, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="test", 
durable=2, expiry-policy=:never, timeout=0, dynamic=false, 
capabilities=@PN_SYMBOL[:topic]], target=@target(41) [durable=0, timeout=0, 
dynamic=false], initial-delivery-count=0]
[0x7f475801ac00]:  <- SASL
[0x7f475801ac00]:  -> SASL
[0x7f475801ac00]:0 -> @sasl-mechanisms(64) 
[sasl-server-mechanisms=@PN_SYMBOL[:ANONYMOUS, :"DIGEST-MD5", :PLAIN]]
[0x7f475801ac00]:0 <- @sasl-init(65) [mechanism=:ANONYMOUS, 
initial-response=b"[email protected]"]
[0x7f475801ac00]:0 -> @sasl-outcome(68) [code=0]
[0x7f475801ac00]:  <- AMQP
[0x7f475801ac00]:0 <- @open(16) 
[container-id="140abf5c-e6f7-4bba-b1b9-cbff557d3069", hostname="localhost", 
channel-max=32767]
[0x7f475801ac00]:0 <- @begin(17) [next-outgoing-id=0, 
incoming-window=2147483647, outgoing-window=2147483647]
[0x7f475801ac00]:0 <- @attach(18) 
[name="140abf5c-e6f7-4bba-b1b9-cbff557d3069-test", handle=0, role=false, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0, 
dynamic=false], target=@target(41) [address="test", durable=0, timeout=0, 
dynamic=false, capabilities=:topic], initial-delivery-count=0]
[0x7f475801ac00]:  -> AMQP
[0x7f475801ac00]:0 -> @open(16) [container-id="Router.A", max-frame-size=16384, 
channel-max=32767, idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY", 
properties={:product="qpid-dispatch-router", :version="0.8.0"}]
[0x7f475801ac00]:0 -> @begin(17) [remote-channel=0, next-outgoing-id=0, 
incoming-window=100, outgoing-window=2147483647]
[0x7f4764006fd0]:1 -> @begin(17) [next-outgoing-id=0, incoming-window=100, 
outgoing-window=2147483647]
[0x7f4764006fd0]:1 -> @attach(18) 
[name="140abf5c-e6f7-4bba-b1b9-cbff557d3069-test", handle=0, role=false, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0, 
dynamic=false], target=@target(41) [address="test", durable=0, timeout=0, 
dynamic=false, capabilities=:topic], initial-delivery-count=0]
[0x7f4760006b70]:0 <- (EMPTY FRAME)
[0x7f4764006fd0]:1 <- @begin(17) [remote-channel=1, next-outgoing-id=1, 
incoming-window=2147483647, outgoing-window=2147483647, handle-max=65535]
[0x7f4764006fd0]:1 <- @attach(18) 
[name="140abf5c-e6f7-4bba-b1b9-cbff557d3069-test", handle=0, role=true, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [], target=@target(41) 
[address="test", durable=0, expiry-policy=:"session-end", timeout=0, 
dynamic=false, capabilities=@PN_SYMBOL[:topic]]]
[0x7f4764006fd0]:1 <- @flow(19) [next-incoming-id=0, 
incoming-window=2147483647, next-outgoing-id=1, outgoing-window=2147483647, 
handle=0, delivery-count=0, link-credit=100]
[0x7f475801ac00]:0 -> @attach(18) 
[name="140abf5c-e6f7-4bba-b1b9-cbff557d3069-test", handle=0, role=true, 
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0, 
dynamic=false], target=@target(41) [address="test", durable=0, timeout=0, 
dynamic=false, capabilities=@PN_SYMBOL[:topic]], initial-delivery-count=0]
[0x7f475801ac00]:0 -> @flow(19) [next-incoming-id=0, incoming-window=100, 
next-outgoing-id=0, outgoing-window=2147483647, handle=0, delivery-count=0, 
link-credit=100, drain=false]
[0x7f475801ac00]:0 <- @transfer(20) [handle=0, delivery-id=0, 
delivery-tag=b"1", message-format=0, settled=false, more=false] (70) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x01@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x03one"
[0x7f475801ac00]:0 <- @transfer(20) [handle=0, delivery-id=1, 
delivery-tag=b"2", message-format=0, settled=false, more=false] (70) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x02@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x03two"
[0x7f475801ac00]:0 <- @transfer(20) [handle=0, delivery-id=2, 
delivery-tag=b"3", message-format=0, settled=false, more=false] (72) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x03@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x05three"
[0x7f475801ac00]:0 <- @transfer(20) [handle=0, delivery-id=3, 
delivery-tag=b"4", message-format=0, settled=false, more=false] (73) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x04@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x06detach"
[0x7f4764006fd0]:1 -> @transfer(20) [handle=0, delivery-id=0, 
delivery-tag=b"1", message-format=0, settled=false, more=false] (70) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x01@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x03one"
[0x7f4764006fd0]:1 -> @transfer(20) [handle=0, delivery-id=1, 
delivery-tag=b"2", message-format=0, settled=false, more=false] (70) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x02@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x03two"
[0x7f4764006fd0]:1 -> @transfer(20) [handle=0, delivery-id=2, 
delivery-tag=b"3", message-format=0, settled=false, more=false] (72) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x03@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x05three"
[0x7f4764006fd0]:1 -> @transfer(20) [handle=0, delivery-id=3, 
delivery-tag=b"4", message-format=0, settled=false, more=false] (73) 
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00#\x00\x00\x00\x0dS\x04@@@@@@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00Sw\xa0\x06detach"
[0x7f4764006fd0]:1 <- @disposition(21) [role=true, first=0, last=0, 
settled=true, state=@accepted(36) []]
[0x7f4764006fd0]:1 <- @disposition(21) [role=true, first=1, last=1, 
settled=true, state=@accepted(36) []]
[0x7f4764006fd0]:1 <- @disposition(21) [role=true, first=2, last=2, 
settled=true, state=@accepted(36) []]
[0x7f4764006fd0]:1 <- @disposition(21) [role=true, first=3, last=3, 
settled=true, state=@accepted(36) []]
[0x7f475801ac00]:0 -> @disposition(21) [role=true, first=0, last=3, 
settled=true, state=@accepted(36) []]
[0x7f475801ac00]:0 <- @close(24) []
[0x7f475801ac00]:  <- EOS
[0x7f475801ac00]:0 -> @close(24) []
[0x7f475801ac00]:  -> EOS
[0x7f4764006fd0]:1 -> @detach(22) [handle=0, closed=false, error=@error(29) 
[condition=:"qd:routed-link-lost", description="Connectivity to the peer 
container was lost"]]
[0x7f4764006fd0]:0 <- @transfer(20) [handle=0, delivery-id=0, 
delivery-tag=b"0", message-format=0] (66) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xc1\x13\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x01@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x03one"
[0x7f4764006fd0]:1 <- @detach(22) [handle=0]
[0x7f4764006fd0]:1 -> @end(23) []
[0x7f4760006b70]:0 -> @transfer(20) [handle=0, delivery-id=0, 
delivery-tag=b"0", message-format=0, settled=false, more=false] (72) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xd1\x00\x00\x00\x16\x00\x00\x00\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x01@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x03one"
[0x7f4764006fd0]:0 <- @transfer(20) [handle=0, delivery-id=1, 
delivery-tag=b"1", message-format=0] (66) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xc1\x13\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x02@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x03two"
[0x7f4760006b70]:0 -> @transfer(20) [handle=0, delivery-id=1, 
delivery-tag=b"1", message-format=0, settled=false, more=false] (72) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xd1\x00\x00\x00\x16\x00\x00\x00\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x02@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x03two"
[0x7f4764006fd0]:0 <- @transfer(20) [handle=0, delivery-id=2, 
delivery-tag=b"2", message-format=0] (68) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xc1\x13\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x03@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x05three"
[0x7f4764006fd0]:0 <- @transfer(20) [handle=0, delivery-id=3, 
delivery-tag=b"3", message-format=0] (69) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xc1\x13\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x04@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x06detach"
[0x7f4760006b70]:0 <- @disposition(21) [role=true, first=0, last=0, 
settled=true, state=@accepted(36) []]
[0x7f4760006b70]:0 <- @flow(19) [next-incoming-id=2, 
incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647, 
handle=0, delivery-count=2, link-credit=9, drain=false]
[0x7f4760006b70]:0 <- @disposition(21) [role=true, first=1, last=1, 
settled=true, state=@accepted(36) []]
[0x7f4764006fd0]:0 -> @flow(19) [next-incoming-id=5, incoming-window=100, 
next-outgoing-id=0, outgoing-window=2147483647, handle=0, delivery-count=4, 
link-credit=7, drain=false]
[0x7f4764006fd0]:0 -> @disposition(21) [role=true, first=0, last=1, 
settled=true, state=@accepted(36) []]
[0x7f4760006b70]:0 -> @transfer(20) [handle=0, delivery-id=2, 
delivery-tag=b"2", message-format=0, settled=false, more=false] (74) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xd1\x00\x00\x00\x16\x00\x00\x00\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x03@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x05three"
[0x7f4760006b70]:0 -> @transfer(20) [handle=0, delivery-id=3, 
delivery-tag=b"3", message-format=0, settled=false, more=false] (75) 
"\x00Sp\xc0\x05\x04@@@B\x00Sr\xd1\x00\x00\x00\x16\x00\x00\x00\x02\xa3\x0ex-opt-jms-destQ\x00\x00Ss\xc0\x13\x0cS\x04@\xa1\x04test@@@@@@@@C\x00Sw\xa0\x06detach"
[0x7f4764006fd0]:1 <- @end(23) []
[0x7f4760006b70]:0 <- @flow(19) [next-incoming-id=4, 
incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647, 
handle=0, delivery-count=4, link-credit=9, drain=false]
[0x7f4760006b70]:0 <- @disposition(21) [role=true, first=2, last=3, 
settled=true, state=@accepted(36) []]
[0x7f4760006b70]:0 <- @detach(22) [handle=0, closed=false]

disposition for deliveries 2 and 3 is sent by receiving client *before* the 
detach

[0x7f4760006b70]:0 <- @close(24) []
[0x7f4760006b70]:  <- EOS
[0x7f4760006b70]:0 -> @close(24) []
[0x7f4760006b70]:  -> EOS
[0x7f4764006fd0]:0 -> @detach(22) [handle=0, closed=false]
[0x7f4764006fd0]:0 <- @detach(22) [handle=0]
[0x7f4764006fd0]:0 -> @disposition(21) [role=true, first=2, last=2, 
settled=true]
[0x7f4764006fd0]:0 -> @disposition(21) [role=true, first=3, last=3, 
settled=true]

dispositions for deliveries 2 and 3 are relayed to broker *after* the detach

[0x7f4764006fd0]:0 -> @end(23) []
[0x7f4764006fd0]:0 <- @end(23) []
{noformat}

The same thing happens (slightly less frequently) when the subscriber simply 
closes the connection after sending disposition, without explicitly detaching 
the link:

{noformat}
[0x1a5ae60]:0 <- @disposition(21) [role=true, first=3, last=3, settled=true, 
state=@accepted(36) []]
[0x1a5ae60]:0 <- @close(24) []
[0x1a5ae60]:  <- EOS
[0x1a5ae60]:0 -> @close(24) []
[0x1a5ae60]:  -> EOS
[0x7f6754006fd0]:1 <- @end(23) []
[0x7f6754006fd0]:0 -> @detach(22) [handle=0, closed=false, error=@error(29) 
[condition=:"qd:routed-link-lost", description="Connectivity to the peer 
container was lost"]]
[0x7f6754006fd0]:0 <- @detach(22) [handle=0]
[0x7f6754006fd0]:0 -> @disposition(21) [role=true, first=3, last=3, 
settled=true]
[0x7f6754006fd0]:0 -> @end(23) []
[0x7f6754006fd0]:0 <- @end(23) []
{noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to