[
https://issues.apache.org/jira/browse/DISPATCH-2083?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17347776#comment-17347776
]
Ganesh Murthy commented on DISPATCH-2083:
-----------------------------------------
I still have been unable to reproduce the problem but the following is a
possibility
{noformat}
1. First attach sent
2. Second attach sent
3. First detach sent
4. Second detach sent
5. Response to first attach (increments n_senders to 1)
6. Response to first detach arrives (decrements n_senders to 0)
7. Response to second detach arrives (decrements n_senders to -1 - BOOM)
8. Response to second attach arrives.
the above is not what the log is showing but it could have very well happened
Again without reproducing this error, there is no chance of predicting that the
above were the exact sequence of events but since the attaches and detaches are
so close to each other, the above is a possibility {noformat}
After running the test repeatedly on an s390x system with RHEL 8, I have been
unable to reproduce it and hence hesitant to fix it. I am downgrading the
priority on this to Minor
> [s390x] container.c:700: qd_container_handle_event: Assertion
> `qd_conn->n_senders >= 0' failed
> ----------------------------------------------------------------------------------------------
>
> Key: DISPATCH-2083
> URL: https://issues.apache.org/jira/browse/DISPATCH-2083
> Project: Qpid Dispatch
> Issue Type: Test
> Affects Versions: 1.16.0
> Environment: Travis CI Focal on s390x
> Reporter: Jiri Daněk
> Priority: Major
> Fix For: 1.17.0
>
>
> https://travis-ci.com/github/apache/qpid-dispatch/jobs/501211930#L5514
> PR build, but IMO very unlikely the PR caused the issue.
> {noformat}
> 38: test_32_two_router_waypoint
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest) ... n_sent=10
> n_rcvd=10 n_thru=10 n_waypoint_rcvd=10
> 38: n_sent=10 n_rcvd=10 n_thru=10 n_waypoint_rcvd=10
> 38: n_sent=10 n_rcvd=10 n_thru=10 n_waypoint_rcvd=10
> 38: WaypointTest
> 38: WaypointTest
> 38: FAIL
> 38: test_33_one_router_waypoint_no_tenant_external_addr
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest) ... ok
> 38: test_34_one_router_waypoint_external_addr
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest) ... ok
> 38: test_35_two_router_waypoint_no_tenant_external_addr
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest) ... n_sent=10
> n_rcvd=10 n_thru=10 n_waypoint_rcvd=10
> 38: n_sent=10 n_rcvd=10 n_thru=10 n_waypoint_rcvd=10
> 38: WaypointTest
> 38: WaypointTest
> 38: FAIL
> 38: test_36_two_router_waypoint_external_addr
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest) ...
> WaypointTest
> 38: WaypointTest
> 38: FAIL
> 38:
> 38: Router B output file:
> 38: >>>>
> 38: qdrouterd: /home/travis/build/apache/qpid-dispatch/src/container.c:700:
> qd_container_handle_event: Assertion `qd_conn->n_senders >= 0' failed.
> 38:
> 38: <<<<
> 38:
> 38: Router B output file:
> 38: >>>>
> 38: qdrouterd: /home/travis/build/apache/qpid-dispatch/src/container.c:700:
> qd_container_handle_event: Assertion `qd_conn->n_senders >= 0' failed.
> 38:
> 38: <<<<
> 38:
> 38: Router B command file:
> 38: >>>>
> 38: qdrouterd -c B.conf -I /home/travis/build/apache/qpid-dispatch/python
> 38: pid=13121
> 38:
> 38: <<<<
> 38:
> 38: Router B log file tail:
> 38: >>>>
> 38: 2021-04-26 19:50:34.632813 +0000 ROUTER_CORE (debug) [C23][L67][D394]
> Delivery outcome : is unknown (0x0)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:392)
> 38: 2021-04-26 19:50:34.633027 +0000 POLICY (debug) [C23] Connection
> '127.0.0.1:55896' closed with resources n_sessions=0, n_senders=0,
> n_receivers=0, sessions_denied=0, senders_denied=0, receivers_denied=0,
> max_message_size_denied:0, nConnections= 3.
> (/home/travis/build/apache/qpid-dispatch/src/policy.c:318)
> 38: 2021-04-26 19:50:34.633247 +0000 ROUTER_CORE (debug) [C23][L67][D394]
> Delivery decref_CT: rc:0 qdr_link_cleanup_deliveries_CT - remove from
> unsettled list
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.633525 +0000 ROUTER_CORE (trace) [C23][L67][D395] :in
> qdr_delivery_unlink_peers_CT out: [C1][L22][D397]
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:542)
> 38: 2021-04-26 19:50:34.633711 +0000 ROUTER_CORE (debug) [C23][L67][D395]
> Delivery decref_CT: rc:1 qdr_delivery_unlink_peers_CT - unlinked from peer
> (delivery)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.633893 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery decref_CT: rc:2 qdr_delivery_unlink_peers_CT - unlinked from
> delivery (peer)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.634098 +0000 ROUTER_CORE (debug) [C23][L67][D395]
> Delivery outcome : is unknown (0x0)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:392)
> 38: 2021-04-26 19:50:34.634283 +0000 ROUTER_CORE (debug) [C23][L67][D395]
> Delivery decref_CT: rc:0 qdr_link_cleanup_deliveries_CT - remove from
> unsettled list
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.634579 +0000 ROUTER_CORE (info) [C23][L67] Link lost:
> del=10 presett=0 psdrop=0 acc=7 rej=0 rel=0 mod=0 delay1=0 delay10=0
> blocked=no
> (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1074)
> 38: 2021-04-26 19:50:34.634768 +0000 ROUTER_CORE (trace) Core action
> 'link_detach'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.635004 +0000 ROUTER_CORE (info) Auto Link Activation
> Failed. 'autoLink/1' on container ALC
> (/home/travis/build/apache/qpid-dispatch/src/router_core/route_control.c:136)
> 38: 2021-04-26 19:50:34.635184 +0000 ROUTER_MA (debug) No Longer Local Dest:
> M0hosted-group-1/queue.waypoint
> (/home/travis/build/apache/qpid-dispatch/src/router_core/modules/mobile_sync/mobile.c:765)
> 38: 2021-04-26 19:50:34.635417 +0000 ROUTER_CORE (info) [C23][L68] Link lost:
> del=10 presett=0 psdrop=0 acc=10 rej=0 rel=0 mod=0 delay1=0 delay10=0
> blocked=no
> (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1074)
> 38: 2021-04-26 19:50:34.635618 +0000 PROTOCOL (trace) [C1]:FRAME: 5 <-
> @disposition(21) [role=true, first=11, settled=true, state=@accepted(36) []]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.635749 +0000 ROUTER_CORE (trace) Core action
> 'update_delivery'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.635981 +0000 ROUTER_CORE (debug) [C1][L22][D393]
> Delivery decref_CT: rc:1 qdr_delivery_anycast_update CT - dlv removed from
> unsettled
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.636146 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery incref: rc:3 qdr_delivery_update_disposition - add to action
> list (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:115)
> 38: 2021-04-26 19:50:34.636293 +0000 ROUTER_CORE (debug) [C1][L22][D393]
> Delivery decref_CT: rc:0 qdr_update_delivery_CT - remove from action
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.636475 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery decref: rc:2 removed reference from pn_delivery
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:149)
> 38: 2021-04-26 19:50:34.636623 +0000 ROUTER_CORE (debug) [C1][L22][D393]
> Delivery outcome : is accepted (0x24)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:392)
> 38: 2021-04-26 19:50:34.636842 +0000 ROUTER_CORE (trace) Core action
> 'update_delivery'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.637065 +0000 ROUTER_CORE (debug) [C1][L22][D396]
> Delivery decref_CT: rc:1 qdr_delivery_anycast_update CT - dlv removed from
> unsettled
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.637223 +0000 ROUTER_CORE (debug) [C1][L22][D396]
> Delivery decref_CT: rc:0 qdr_update_delivery_CT - remove from action
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.637414 +0000 ROUTER_CORE (debug) [C1][L22][D396]
> Delivery outcome : is accepted (0x24)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:392)
> 38: 2021-04-26 19:50:34.637624 +0000 ROUTER_CORE (trace) Core action
> 'connection_opened'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.637905 +0000 ROUTER_CORE (info) Auto Link Activated
> 'autoLink/0' on container ALC
> (/home/travis/build/apache/qpid-dispatch/src/router_core/route_control.c:136)
> 38: 2021-04-26 19:50:34.638449 +0000 ROUTER_CORE (info) [C24][L69] Link
> attached: dir=in source={hosted-group-1/queue.waypoint expire:link}
> target={<none> expire:link}
> (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 38: 2021-04-26 19:50:34.638646 +0000 ROUTER_CORE (info) Auto Link Activated
> 'autoLink/1' on container ALC
> (/home/travis/build/apache/qpid-dispatch/src/router_core/route_control.c:136)
> 38: 2021-04-26 19:50:34.639215 +0000 ROUTER_CORE (info) [C24][L70] Link
> attached: dir=out source={<none> expire:link}
> target={hosted-group-1/queue.waypoint expire:link}
> (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 38: 2021-04-26 19:50:34.639441 +0000 ROUTER_CORE (trace) Core action
> 'connection_closed'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.639618 +0000 ROUTER_CORE (info) Auto Link Deactivated
> 'autoLink/0' on container ALC
> (/home/travis/build/apache/qpid-dispatch/src/router_core/route_control.c:136)
> 38: 2021-04-26 19:50:34.639823 +0000 ROUTER_CORE (info) Auto Link Deactivated
> 'autoLink/1' on container ALC
> (/home/travis/build/apache/qpid-dispatch/src/router_core/route_control.c:136)
> 38: 2021-04-26 19:50:34.640038 +0000 ROUTER_CORE (info) [C23] Connection
> Closed
> (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1557)
> 38: 2021-04-26 19:50:34.640295 +0000 ROUTER_CORE (trace) Core action
> 'update_delivery'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.640423 +0000 PROTOCOL (trace) [C24]:FRAME: 0 ->
> @begin(17) [next-outgoing-id=0, incoming-window=2147483647,
> outgoing-window=2147483647]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.640582 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery decref_CT: rc:1 qdr_delivery_anycast_update CT - dlv removed from
> unsettled
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.640715 +0000 PROTOCOL (trace) [C24]:FRAME: 0 ->
> @attach(18) [name="qdlink.udGSQRjKmumOJev", handle=0, role=true,
> snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
> [address="hosted-group-1/queue.waypoint", durable=0,
> expiry-policy=:"link-detach", timeout=0, dynamic=false], target=@target(41)
> [durable=0, expiry-policy=:"link-detach", timeout=0, dynamic=false],
> initial-delivery-count=0, max-message-size=0]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.640872 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery decref_CT: rc:0 qdr_update_delivery_CT - remove from action
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:640)
> 38: 2021-04-26 19:50:34.641004 +0000 PROTOCOL (trace) [C24]:FRAME: 0 ->
> @attach(18) [name="qdlink.nf9w9DwBT2a6cC1", handle=1, role=false,
> snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0,
> expiry-policy=:"link-detach", timeout=0, dynamic=false], target=@target(41)
> [address="hosted-group-1/queue.waypoint", durable=0,
> expiry-policy=:"link-detach", timeout=0, dynamic=false],
> initial-delivery-count=0, max-message-size=0]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.641151 +0000 ROUTER_CORE (debug) [C1][L22][D397]
> Delivery outcome : is accepted (0x24)
> (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:392)
> 38: 2021-04-26 19:50:34.641337 +0000 PROTOCOL (trace) [C24]:FRAME: 0 ->
> @detach(22) [handle=0, closed=true]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.641483 +0000 ROUTER_CORE (trace) Core action
> 'link_detach_sent'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.641615 +0000 PROTOCOL (trace) [C24]:FRAME: 0 ->
> @detach(22) [handle=1, closed=true]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.641756 +0000 ROUTER_CORE (trace) Core action
> 'link_detach_sent'
> (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 38: 2021-04-26 19:50:34.644030 +0000 PROTOCOL (trace) [C24]:FRAME: 0 <-
> @begin(17) [remote-channel=0, next-outgoing-id=0, incoming-window=2147483647,
> outgoing-window=2147483647]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.644208 +0000 PROTOCOL (trace) [C24]:FRAME: 0 <-
> @attach(18) [name="qdlink.udGSQRjKmumOJev", handle=0, role=false,
> snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
> [address="hosted-group-1/queue.waypoint", durable=0, timeout=0,
> dynamic=false], target=@target(41) [durable=0, timeout=0, dynamic=false],
> initial-delivery-count=0, max-message-size=0]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.644379 +0000 PROTOCOL (trace) [C24]:FRAME: 0 <-
> @attach(18) [name="qdlink.nf9w9DwBT2a6cC1", handle=1, role=true,
> snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0,
> timeout=0, dynamic=false], target=@target(41)
> [address="hosted-group-1/queue.waypoint", durable=0, timeout=0,
> dynamic=false], initial-delivery-count=0, max-message-size=0]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.644518 +0000 PROTOCOL (trace) [C24]:FRAME: 0 <-
> @detach(22) [handle=0, closed=true]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.644653 +0000 PROTOCOL (trace) [C24]:FRAME: 0 <-
> @detach(22) [handle=1, closed=true]
> (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 38: 2021-04-26 19:50:34.644792 +0000 CONTAINER (trace) Closed sender link
> qdlink.udGSQRjKmumOJev. n_senders: -1
> (/home/travis/build/apache/qpid-dispatch/src/container.c:697)
> 38:
> 38: <<<<
> 38: ERROR
> 38:
> 38: ======================================================================
> 38: ERROR: tearDownClass
> (system_tests_multi_tenancy_policy.RouterMultitenantPolicyTest)
> 38: ----------------------------------------------------------------------
> 38: Traceback (most recent call last):
> 38: File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py",
> line 865, in tearDownClass
> 38: cls.tester.teardown()
> 38: File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py",
> line 808, in teardown
> 38: raise RuntimeError("Errors during teardown: \n\n%s" %
> "\n\n".join([str(e) for e in errors]))
> 38: RuntimeError: Errors during teardown:
> 38:
> 38: Process 13121 error: exit code -6, expected -1
> 38: qdrouterd -c B.conf -I /home/travis/build/apache/qpid-dispatch/python
> 38:
> /home/travis/build/apache/qpid-dispatch/build/tests/system_test.dir/system_tests_multi_tenancy_policy/RouterMultitenantPolicyTest/setUpClass/B-2.cmd
> 38: >>>>
> 38: qdrouterd: /home/travis/build/apache/qpid-dispatch/src/container.c:700:
> qd_container_handle_event: Assertion `qd_conn->n_senders >= 0' failed.
> 38: <<<<
> 38:
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
