You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Jiri Daněk (Jira)" <ji...@apache.org> on 2021/05/26 13:56:00 UTC

[jira] [Comment Edited] (DISPATCH-2085) system_tests_fallback_dest failure - addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed

    [ https://issues.apache.org/jira/browse/DISPATCH-2085?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17351802#comment-17351802 ] 

Jiri Daněk edited comment on DISPATCH-2085 at 5/26/21, 1:55 PM:
----------------------------------------------------------------

And again, this time on Fedora 34; It is Github Actions, so test logs are available for download.

https://github.com/apache/qpid-dispatch/runs/2675411836?check_suite_focus=true#step:25:2158

{noformat}
63: E           /__w/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/tests/system_test.dir/system_tests_fallback_dest/RouterTest/setUpClass/EA2-4.cmd
63: E           >>>>
63: E           2021-05-26 13:26:17.010695 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
63: E           2021-05-26 13:26:17.010940 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
63: E           qdrouterd: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/modules/edge_router/addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed.
63: E           <<<<
{noformat}


was (Author: jdanek):
And again, this time on Fedora 34

https://github.com/apache/qpid-dispatch/runs/2675411836?check_suite_focus=true#step:25:2158

{noformat}
63: E           /__w/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/tests/system_test.dir/system_tests_fallback_dest/RouterTest/setUpClass/EA2-4.cmd
63: E           >>>>
63: E           2021-05-26 13:26:17.010695 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
63: E           2021-05-26 13:26:17.010940 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
63: E           qdrouterd: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/modules/edge_router/addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed.
63: E           <<<<
{noformat}

> system_tests_fallback_dest failure - addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed
> ----------------------------------------------------------------------------------------------------------------
>
>                 Key: DISPATCH-2085
>                 URL: https://issues.apache.org/jira/browse/DISPATCH-2085
>             Project: Qpid Dispatch
>          Issue Type: Test
>    Affects Versions: 1.16.0
>         Environment: Travis CI Focal
>            Reporter: Jiri Daněk
>            Priority: Major
>             Fix For: 1.17.0
>
>
> First spotted on s390x, https://travis-ci.com/github/apache/qpid-dispatch/jobs/501153572#L6607
> {noformat}
> 62: Router EA2 output file:
> 62: >>>>
> 62: 2021-04-26 16:56:05.615255 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 2021-04-26 16:56:05.615411 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: qdrouterd: /home/travis/build/apache/qpid-dispatch/src/router_core/modules/edge_router/addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed.
> 62: 
> 62: <<<<
> 62: 
> 62: Router EA2 command file:
> 62: >>>>
> 62: qdrouterd -c EA2.conf -I /home/travis/build/apache/qpid-dispatch/python
> 62: pid=14036
> 62: 
> 62: <<<<
> 62: 
> 62: Router EA2 log file tail:
> 62: >>>>
> 62: 2021-04-26 16:58:05.686184 +0000 ROUTER_CORE (trace) Core action 'link_detach' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:05.686235 +0000 ROUTER_CORE (info) [C4][L12] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1074)
> 62: 2021-04-26 16:58:05.686281 +0000 ROUTER_CORE (trace) Core action 'connection_closed' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:05.686346 +0000 ROUTER_CORE (info) [C4] Connection Closed (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1557)
> 62: 2021-04-26 16:58:05.705484 +0000 SERVER (trace) Accepting connection on 0.0.0.0:23020 (/home/travis/build/apache/qpid-dispatch/src/server.c:852)
> 62: 2021-04-26 16:58:05.705577 +0000 SERVER (trace) [C5]: Accepting incoming connection to '0.0.0.0:23020' (/home/travis/build/apache/qpid-dispatch/src/server.c:606)
> 62: 2021-04-26 16:58:05.705691 +0000 POLICY (trace) ALLOW Connection '127.0.0.1' based on global connection count. nConnections= 1 (/home/travis/build/apache/qpid-dispatch/src/policy.c:271)
> 62: 2021-04-26 16:58:05.705782 +0000 SERVER (info) [C5] Accepted connection to 0.0.0.0:23020 from 127.0.0.1:37922 (/home/travis/build/apache/qpid-dispatch/src/server.c:750)
> 62: 2021-04-26 16:58:05.706152 +0000 PROTOCOL (trace) [C5]:FRAME:   <- SASL (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.706180 +0000 PROTOCOL (trace) [C5]:FRAME:   -> SASL (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.706590 +0000 PROTOCOL (trace) [C5]:FRAME: 0 -> @sasl-mechanisms(64) [sasl-server-mechanisms=@PN_SYMBOL[:ANONYMOUS]] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.706949 +0000 PROTOCOL (trace) [C5]:FRAME: 0 <- @sasl-init(65) [mechanism=:ANONYMOUS, initial-response=b"anonymous@travis-job-apache-qpid-dispatch-501153572"] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707025 +0000 PROTOCOL (trace) [C5]:FRAME: 0 -> @sasl-outcome(68) [code=0] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707319 +0000 PROTOCOL (trace) [C5]:FRAME:   <- AMQP (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707363 +0000 PROTOCOL (trace) [C5]:FRAME: 0 <- @open(16) [container-id="ac3fab39-661e-44f4-8361-5866a600788d", hostname="0.0.0.0", channel-max=32767] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707432 +0000 PROTOCOL (trace) [C5]:FRAME: 0 <- @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707500 +0000 PROTOCOL (trace) [C5]:FRAME: 0 <- @attach(18) [name="dest.32_primary_receiver", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="dest.32", 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)
> 62: 2021-04-26 16:58:05.707557 +0000 PROTOCOL (trace) [C5]:FRAME: 0 <- @flow(19) [incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647, handle=0, delivery-count=0, link-credit=10, drain=false] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707645 +0000 ROUTER_CORE (info) [C5] Connection Opened: dir=in host=127.0.0.1:37922 vhost= encrypted=no auth=ANONYMOUS user=anonymous container_id=ac3fab39-661e-44f4-8361-5866a600788d props= (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:135)
> 62: 2021-04-26 16:58:05.707703 +0000 ROUTER_CORE (trace) Core action 'connection_opened' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:05.707788 +0000 ROUTER_CORE (trace) Core action 'link_first_attach' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:05.707827 +0000 PROTOCOL (trace) [C5]:FRAME:   -> AMQP (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707873 +0000 DEFAULT (trace) Parse tree search for 'dest.32' (/home/travis/build/apache/qpid-dispatch/src/parse_tree.c:704)
> 62: 2021-04-26 16:58:05.707910 +0000 PROTOCOL (trace) [C5]:FRAME: 0 -> @open(16) [container-id="EA2", max-frame-size=16384, channel-max=32767, idle-time-out=60000, offered-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], desired-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], properties={:product="qpid-dispatch-router", :version="1.16.0-SNAPSHOT", :"qd.conn-id"=5}] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:05.707959 +0000 DEFAULT (trace) Parse tree match not found (/home/travis/build/apache/qpid-dispatch/src/parse_tree.c:692)
> 62: 2021-04-26 16:58:05.707996 +0000 PROTOCOL (trace) [C5]: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)
> 62: 2021-04-26 16:58:05.708043 +0000 DEFAULT (trace) Parse tree search for 'dest.32' (/home/travis/build/apache/qpid-dispatch/src/parse_tree.c:704)
> 62: 2021-04-26 16:58:05.708196 +0000 ROUTER_CORE (info) [C5][L13] Link attached: dir=out source={dest.32 expire:sess} target={<none> expire:sess} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1838)
> 62: 2021-04-26 16:58:05.708231 +0000 ROUTER_CORE (trace) Core action 'link_flow' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:05.708353 +0000 PROTOCOL (trace) [C5]:FRAME: 0 -> @attach(18) [name="dest.32_primary_receiver", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="dest.32", durable=0, expiry-policy=:"session-end", timeout=0, dynamic=false], target=@target(41) [durable=0, expiry-policy=:"session-end", timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:06.665127 +0000 ROUTER_CORE (trace) Core action 'process_tick' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:07.665236 +0000 ROUTER_CORE (trace) Core action 'process_tick' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:07.684326 +0000 SERVER (trace) [C6] Connecting to 127.0.0.1:23012 (/home/travis/build/apache/qpid-dispatch/src/server.c:1202)
> 62: 2021-04-26 16:58:07.684656 +0000 PROTOCOL (trace) [C6]:FRAME:   -> SASL (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.686448 +0000 PROTOCOL (trace) [C6]:FRAME:   <- SASL (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.686506 +0000 PROTOCOL (trace) [C6]:FRAME: 0 <- @sasl-mechanisms(64) [sasl-server-mechanisms=@PN_SYMBOL[:ANONYMOUS]] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.686654 +0000 PROTOCOL (trace) [C6]:FRAME: 0 -> @sasl-init(65) [mechanism=:ANONYMOUS, initial-response=b"anonymous@travis-job-apache-qpid-dispatch-501153572"] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.687181 +0000 PROTOCOL (trace) [C6]:FRAME: 0 <- @sasl-outcome(68) [code=0] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.687225 +0000 PROTOCOL (trace) [C6]:FRAME:   -> AMQP (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.687326 +0000 PROTOCOL (trace) [C6]:FRAME: 0 -> @open(16) [container-id="EA2", hostname="127.0.0.1", max-frame-size=16384, channel-max=32767, idle-time-out=60000, offered-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], desired-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], properties={:product="qpid-dispatch-router", :version="1.16.0-SNAPSHOT", :"qd.conn-id"=6}] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.689045 +0000 PROTOCOL (trace) [C6]:FRAME:   <- AMQP (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.689107 +0000 PROTOCOL (trace) [C6]:FRAME: 0 <- @open(16) [container-id="INT.A", max-frame-size=16384, channel-max=32767, idle-time-out=60000, offered-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], desired-capabilities=@PN_SYMBOL[:"ANONYMOUS-RELAY", :"qd.streaming-links"], properties={:product="qpid-dispatch-router", :version="1.16.0-SNAPSHOT", :"qd.conn-id"=28}] (/home/travis/build/apache/qpid-dispatch/src/server.c:111)
> 62: 2021-04-26 16:58:07.689596 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=out host=127.0.0.1:23012 vhost= encrypted=no auth=ANONYMOUS user=(null) container_id=INT.A props={:product="qpid-dispatch-router", :version="1.16.0-SNAPSHOT", :"qd.conn-id"=28} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:135)
> 62: 2021-04-26 16:58:07.689761 +0000 ROUTER_CORE (trace) Core action 'connection_opened' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
> 62: 2021-04-26 16:58:07.689796 +0000 ROUTER_CORE (info) Edge connection (id=6) to interior established (/home/travis/build/apache/qpid-dispatch/src/router_core/modules/edge_router/connection_manager.c:56)
> 62: 2021-04-26 16:58:07.689912 +0000 ROUTER_CORE (info) [C6][L14] Link attached: dir=out source={<none> expire:link} target={<none> expire:link} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 62: 2021-04-26 16:58:07.690044 +0000 ROUTER_CORE (info) [C6][L15] Link attached: dir=in source={EA2 expire:link caps::"qd.router-edge-downlink"} target={<none> expire:link caps::"qd.router-edge-downlink"} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 62: 2021-04-26 16:58:07.690170 +0000 ROUTER_CORE (info) [C6][L16] Link attached: dir=in source={_$qd.edge_addr_tracking expire:link} target={<none> expire:link} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 62: 2021-04-26 16:58:07.690275 +0000 ROUTER_CORE (info) [C6][L17] Link attached: dir=in source={dest.32 expire:link} target={<none> expire:link} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 62: 2021-04-26 16:58:07.690438 +0000 ROUTER_CORE (info) [C6][L18] Link attached: dir=out source={<none> expire:link} target={dest.32 expire:link caps::"qd.fallback"} (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1173)
> 62: 
> 62: <<<<
> 62: 
> 62: Router EA1 output file:
> 62: >>>>
> 62: 2021-04-26 16:56:05.467836 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 2021-04-26 16:56:05.467996 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 
> 62: <<<<
> 62: 
> 62: Router EA1 debug dump file:
> 62: >>>>
> 62: alloc.c: Items of type 'qd_timer_t' remain allocated at shutdown: 1 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_buffer_t' remain allocated at shutdown: 13 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_connector_t' remain allocated at shutdown: 1 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_message_t' remain allocated at shutdown: 13 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_message_content_t' remain allocated at shutdown: 13 (SUPPRESSED)
> 62: alloc.c: Items of type 'qdr_delivery_t' remain allocated at shutdown: 13 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_link_ref_t' remain allocated at shutdown: 13 (SUPPRESSED)
> 62: 
> 62: <<<<
> 62: 
> 62: Router INT.B output file:
> 62: >>>>
> 62: 2021-04-26 16:56:05.209684 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 2021-04-26 16:56:05.209868 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 
> 62: <<<<
> 62: 
> 62: Router INT.B debug dump file:
> 62: >>>>
> 62: alloc.c: Items of type 'qd_timer_t' remain allocated at shutdown: 1 (SUPPRESSED)
> 62: alloc.c: Items of type 'qd_connector_t' remain allocated at shutdown: 1 (SUPPRESSED)
> 62: 
> 62: <<<<
> 62: 
> 62: Router INT.A output file:
> 62: >>>>
> 62: 2021-04-26 16:56:04.950765 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 2021-04-26 16:56:04.951002 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 
> 62: <<<<
> 62: ERROR
> 62: 
> 62: ======================================================================
> 62: ERROR: tearDownClass (system_tests_fallback_dest.RouterTest)
> 62: ----------------------------------------------------------------------
> 62: Traceback (most recent call last):
> 62:   File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py", line 865, in tearDownClass
> 62:     cls.tester.teardown()
> 62:   File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py", line 808, in teardown
> 62:     raise RuntimeError("Errors during teardown: \n\n%s" % "\n\n".join([str(e) for e in errors]))
> 62: RuntimeError: Errors during teardown: 
> 62: 
> 62: Process 14036 error: exit code -6, expected -1
> 62: qdrouterd -c EA2.conf -I /home/travis/build/apache/qpid-dispatch/python
> 62: /home/travis/build/apache/qpid-dispatch/build/tests/system_test.dir/system_tests_fallback_dest/RouterTest/setUpClass/EA2-4.cmd
> 62: >>>>
> 62: 2021-04-26 16:56:05.615255 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: 2021-04-26 16:56:05.615411 +0000 AGENT (warning) Attribute 'dir' of entity 'autoLink' has been deprecated. Use 'direction' instead
> 62: qdrouterd: /home/travis/build/apache/qpid-dispatch/src/router_core/modules/edge_router/addr_proxy.c:323: on_conn_event: Assertion `addr->edge_outlink == 0' failed.
> 62: <<<<
> 62: 
> 62: ======================================================================
> 62: FAIL: test_32_switchover_local_interior_alt_remote_edge (system_tests_fallback_dest.RouterTest)
> 62: ----------------------------------------------------------------------
> 62: Traceback (most recent call last):
> 62:   File "/home/travis/build/apache/qpid-dispatch/tests/system_tests_fallback_dest.py", line 328, in test_32_switchover_local_interior_alt_remote_edge
> 62:     self.assertEqual(None, test.error)
> 62: AssertionError: None != 'Timeout Expired - n_tx=232, n_rx=0, n_rel=8351, phase=0, local_rel=8351'
> 62: 
> 62: ======================================================================
> 62: FAIL: test_38_switchover_mix_4 (system_tests_fallback_dest.RouterTest)
> 62: ----------------------------------------------------------------------
> 62: Traceback (most recent call last):
> 62:   File "/home/travis/build/apache/qpid-dispatch/tests/system_tests_fallback_dest.py", line 376, in test_38_switchover_mix_4
> 62:     self.assertEqual(None, test.error)
> 62: AssertionError: None != 'Timeout Expired - n_tx=0, n_rx=0, n_rel=0, phase=0, local_rel=0'
> 62: 
> 62: ----------------------------------------------------------------------
> 62: Ran 50 tests in 322.245s
> 62: 
> 62: FAILED (failures=2, errors=1)
> 62/74 Test #62: system_tests_fallback_dest ........................***Failed  322.37 sec
> {noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org