Uploaded image for project: 'AMQ Interconnect'
  1. AMQ Interconnect
  2. ENTMQIC-1951

Dispatch Console attempts to re-upgrade existing websocket connection

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • None
    • 1.0.0.GA
    • Router Console
    • None
    • User Experience
      • Restart browser
    • Hide
      • Configure 2 brokers and 2 routers as per ENTMQIC-1947
      • Enable http:yes on a new listener on RouterB
      • Send and receive messages in small batches of 20 to the brokers.
      • Open web console to view messages being sent and received by brokers
      • Connect console via 'Dispatch Router' tab to RouterB
      • No sending or receiving connections at this point
      • Stop brokers, stop routers
      • rm -rf data for brokers
      • Web consoles will auto-logout
      • Start brokers, start routers
      • Dispatch console plugin should start sending data to RouterB as soon as it comes up and connects the autolink to the broker as per ENTMQIC-1949

      Testing the above at the moment always seems to yield valid data on valid web socket connections. However after leaving the browsers open with the Artemis console logged out but the dispatch console plugin still using the connection for a period of days left the state such that the described problem was 100% reproducible. This behaviour in turn is related to the segfault in ENTMQIC-1948. Restarting the browser eliminated reproduction of behaviour.

      Show
      Configure 2 brokers and 2 routers as per ENTMQIC-1947 Enable http:yes on a new listener on RouterB Send and receive messages in small batches of 20 to the brokers. Open web console to view messages being sent and received by brokers Connect console via 'Dispatch Router' tab to RouterB No sending or receiving connections at this point Stop brokers, stop routers rm -rf data for brokers Web consoles will auto-logout Start brokers, start routers Dispatch console plugin should start sending data to RouterB as soon as it comes up and connects the autolink to the broker as per ENTMQIC-1949 Testing the above at the moment always seems to yield valid data on valid web socket connections. However after leaving the browsers open with the Artemis console logged out but the dispatch console plugin still using the connection for a period of days left the state such that the described problem was 100% reproducible. This behaviour in turn is related to the segfault in ENTMQIC-1948 . Restarting the browser eliminated reproduction of behaviour.

      Using the configuration from ENTMQIC-1947 but enabling http on both RouterB after having said configuration up and running with 2 brokers connected to 2 routers we eventually see the following when restarting the brokers and routers to run tests from clean.

      NOTE when the brokers are restarted the browsers are left alone and return to the login screen automatically they continue to send traffic as per ENTMQIC-1949. At this point when RouterB is restarting we see the following where the console is attempting to use an existing websocket connection to talk plain HTTP to the router to request a websocket upgrade:

      [rkieley@ic1rh rh-qpid-dispatch]$ PN_TRACE_FRM=1 qdrouterd -c ./qdrouterd_waypoint_2_whttp.conf
Fri Aug 18 09:30:36 2017 HTTP (info) Initial logging level 7
Fri Aug 18 09:30:36 2017 HTTP (info) Libwebsockets version: 2.1.0 unknown-build-hash
Fri Aug 18 09:30:36 2017 HTTP (info) IPV6 not compiled in
Fri Aug 18 09:30:36 2017 HTTP (info) libev support not compiled in
Fri Aug 18 09:30:36 2017 HTTP (info) libuv support not compiled in
Fri Aug 18 09:30:36 2017 HTTP (info)  Threads: 1 each 1024 fds
Fri Aug 18 09:30:36 2017 HTTP (info)  mem: platform fd map:  8192 bytes
Fri Aug 18 09:30:36 2017 HTTP (info)  Compiled with OpenSSL support
Fri Aug 18 09:30:36 2017 HTTP (info)  mem: per-conn:          512 bytes + protocol rx buf
Fri Aug 18 09:30:36 2017 SERVER (info) Container Name: RouterB
Fri Aug 18 09:30:36 2017 ROUTER (info) Router started in Interior mode, area=0 id=RouterB
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) Allow Unsettled Multicast: no
Fri Aug 18 09:30:36 2017 ROUTER (info) Router Engine Instantiated: id=RouterB instance=1503057636 max_routers=128
Fri Aug 18 09:30:36 2017 AGENT (info) Activating management agent on $_management_internal
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) Router Core thread running. 0/RouterB
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription M/$management
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription L/$management
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription L/qdrouter
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription L/qdrouter.ma
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription T/qdrouter
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription T/qdrouter.ma
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription L/qdhello
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) In-process subscription L/$_management_internal
Fri Aug 18 09:30:36 2017 CONN_MGR (info) Configured Listener: 0.0.0.0:2109 proto=any, role=normal
Fri Aug 18 09:30:36 2017 CONN_MGR (info) Configured Listener: 0.0.0.0:2110 proto=any, role=inter-router
Fri Aug 18 09:30:36 2017 CONN_MGR (info) Configured Listener: 192.168.2.208:5676 proto=any, role=normal
Fri Aug 18 09:30:36 2017 CONN_MGR (info) Configured Connector: localhost:2010 proto=any, role=inter-router
Fri Aug 18 09:30:36 2017 CONN_MGR (info) Configured Connector: localhost:5673 proto=any, role=route-container
Fri Aug 18 09:30:36 2017 POLICY (info) Policy configured maxConnections: 65535, policyDir: '', access rules enabled: 'false'
Fri Aug 18 09:30:36 2017 POLICY (info) Policy fallback defaultVhost is defined: '$default'
Fri Aug 18 09:30:36 2017 SERVER (info) Operational, 4 Threads Running
Fri Aug 18 09:30:36 2017 SERVER (info) Running in DEBUG Mode
[0x1e31d30]:  -> SASL
[0x1e31d30]:  <- SASL
[0x1e31d30]:0 <- @sasl-mechanisms(64) [sasl-server-mechanisms=@PN_SYMBOL[:PLAIN, :ANONYMOUS]]
[0x1e31d30]:0 -> @sasl-init(65) [mechanism=:ANONYMOUS, initial-response=b"anonymous@ic1rh"]
[0x1e31d30]:0 <- @sasl-outcome(68) [code=0]
[0x1e31d30]:  <- AMQP
[0x1e31d30]:  -> AMQP
[0x1e31d30]:0 -> @open(16) [container-id="RouterB", hostname="localhost", max-frame-size=16384, channel-max=32767, idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY", properties={:product="qpid-dispatch-router", :version="0.8.0"}]
[0x1e31d30]:0 <- @open(16) [container-id="broker1", max-frame-size=4294967295, channel-max=65535, idle-time-out=30000, offered-capabilities=@PN_SYMBOL[:"sole-connection-for-container", :"DELAYED_DELIVERY", :"SHARED-SUBS", :"ANONYMOUS-RELAY
"], properties={:product="apache-activemq-artemis", :version="2.0.0.amq-700008-redhat-2"}]
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) Auto Link Activated 'autoLink/0' on connection broker
Fri Aug 18 09:30:36 2017 ROUTER_CORE (info) Auto Link Activated 'autoLink/1' on connection broker
[0x1e31d30]:0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
[0x1e31d30]:1 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
[0x1e31d30]:0 -> @attach(18) [name="qdlink.ShGZWnKojJObdfz", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="waypoint.example", durable=0, expiry-policy=:"link-detach", timeout=0, dynamic=false], tar
get=@target(41) [durable=0, timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
[0x1e31d30]:1 -> @attach(18) [name="qdlink.XevfN3HUX7Qzfit", 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="waypoint.example", durable=0, e
xpiry-policy=:"link-detach", timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
[0x1e31d30]:0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=2147483647, outgoing-window=2147483647, handle-max=65535]
[0x1e31d30]:1 <- @begin(17) [remote-channel=1, next-outgoing-id=1, incoming-window=2147483647, outgoing-window=2147483647, handle-max=65535]
[0x1e31d30]:0 <- @attach(18) [name="qdlink.ShGZWnKojJObdfz", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="waypoint.example", durable=0, expiry-policy=:"link-detach"], target=@target(41) [], incom
plete-unsettled=false, initial-delivery-count=0]
[0x1e31d30]:1 <- @attach(18) [name="qdlink.XevfN3HUX7Qzfit", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [], target=@target(41) [address="waypoint.example", durable=0, expiry-policy=:"link-detach"]]
[0x1e31d30]:1 <- @flow(19) [next-incoming-id=0, incoming-window=2147483647, next-outgoing-id=1, outgoing-window=2147483647, handle=0, delivery-count=0, link-credit=1000]
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 -> (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 -> (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 -> (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x1e31d30]:0 <- (EMPTY FRAME)
[0x7f399c02d380]:  -> AMQP
[0x7f399c02d380]:0 -> @open(16) [container-id=""]
[0x7f399c02d380]:0 -> @close(24) [error=@error(29) [condition=:"amqp:connection:framing-error", description="Unknown protocol detected: 'GET / HTTP/1.1\x0d\x0aHost: 192.168.2.208:5676\x0d\x0aUser-Agent: Mozilla/5.0 (X11; Fedora; Linux x86_
64; rv:52.0) Gecko/20100101 Firefox/52.0\x0d\x0aAccept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\x0d\x0aAccept-Language: en-US,en;q=0.5\x0d\x0aAccept-Encoding: gzip, deflate\x0d\x0aSec-WebSocket-Version: 13\x0d\x0aOr
igin: http://192.168.2.208:8162\x0d\x0aSec-WebSocket-Protocol: binary\x0d\x0aSec-WebSocket-Extensions: permessage-deflate\x0d\x0aSec-WebSocket-Key: yNQ+JgkfFXa7gUGGaNq9sA==\x0d\x0aDNT: 1\x0d\x0aConnection: keep-alive, Upgrade\x0d\x0aPragma
: no-cache\x0d\x0aCache-Control: no-cache\x0d\x0aUpgrade: websocket\x0d\x0a\x0d\x0a'"]]
[0x7f399c02d380]:  -> EOS
[0x1e31d30]:0 <- (EMPTY FRAME)

      If left alone the HTTP GET will then be repeated after every 9 EMPTY_FRAME's.

      Also note that utilizing a curl on a new connection normally succeeds in an upgrade - tested when environment was NOT reproducing the above.

      [rkieley@i7t450s ~]$ curl -X GET -v http://192.168.2.208:5676 -H "Sec-WebSocket-Version: 13" -H "Sec-WebSocket-Protocol: binary" -H "Connection: keep-alive, Upgrade" -H "Upgrade: websocket" -H "Sec-WebSocket-Key: vnRYbh8jrmy4hDSn7mp8Xg==" 
 -H "DNT: 1" -H "Cache-Control: no-cache" -H "Pragma: no-cache" -H "Sec-WebSocket-Extensions: permessage-deflate" -H "Origin: http://192.168.2.208:8162" -H "Accept-Language: en-US,en;q=0.5" -H "Accept: text/html,application/xhtml+xml,appli
cation/xml;q=0.9,*/*;q=0.8" -H "User-Agent: Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
Note: Unnecessary use of -X or --request, GET is already inferred.
* Rebuilt URL to: http://192.168.2.208:5676/
*   Trying 192.168.2.208...
* TCP_NODELAY set
* Connected to 192.168.2.208 (192.168.2.208) port 5676 (#0)
> GET / HTTP/1.1
> Host: 192.168.2.208:5676
> Sec-WebSocket-Version: 13
> Sec-WebSocket-Protocol: binary
> Connection: keep-alive, Upgrade
> Upgrade: websocket
> Sec-WebSocket-Key: vnRYbh8jrmy4hDSn7mp8Xg==
> DNT: 1
> Cache-Control: no-cache
> Pragma: no-cache
> Sec-WebSocket-Extensions: permessage-deflate
> Origin: http://192.168.2.208:8162
> Accept-Language: en-US,en;q=0.5
> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
> User-Agent: Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0
> 
< HTTP/1.1 101 Switching Protocols
< Upgrade: WebSocket
< Connection: Upgrade
< Sec-WebSocket-Accept: 7d0jUHO4ZqbzFTGrwOjASjbXN8o=
< Sec-WebSocket-Protocol: binary
<

              eallen@redhat.com Ernest Allen (Inactive)
              rhn-support-rkieley Roderick Kieley
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: