search

crossbario / crossbar

Crossbar.io - WAMP application router
https://crossbar.io/
Other
2.05k stars 274 forks source link

Recheck possible outdated glitch in WAMP message tracing feature #1190

Open oberstet opened 7 years ago

oberstet commented 7 years ago 
2017-09-15T15:59:27+0200 [Router      30121] 
Traceback (most recent call last):
  File "/home/oberstet/scm/crossbario/crossbar/crossbar/router/router.py", line 253, in process
    self._broker.processPublish(session, msg)
  File "/home/oberstet/scm/crossbario/crossbar/crossbar/router/broker.py", line 633, in processPublish
    txaio.add_callbacks(d, on_authorize_success, on_authorize_error)
  File "/home/oberstet/scm/crossbario/txaio/txaio/tx.py", line 491, in add_callbacks
    future.addCallbacks(callback, errback)
  File "/home/oberstet/cpy362_3/lib/python3.6/site-packages/twisted/internet/defer.py", line 310, in addCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File "/home/oberstet/cpy362_3/lib/python3.6/site-packages/twisted/internet/defer.py", line 653, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/home/oberstet/scm/crossbario/crossbar/crossbar/router/broker.py", line 557, in on_authorize_success
    last_msg = message.Event.parse(msg.marshal())
  File "/home/oberstet/scm/crossbario/autobahn-python/autobahn/wamp/message.py", line 2464, in parse
    raise ProtocolError("invalid type {0} for 'args' in EVENT".format(type(args)))
autobahn.wamp.exception.ProtocolError: invalid type <class 'tuple'> for 'args' in EVENT
oberstet commented 7 years ago

There is a glitch with the last flag an WAMP meta events. Eg consider the following block from here https://gist.githubusercontent.com/oberstet/4071ae81cdd8d46c6367eb3c272304d2/raw/f732ab681848b8c860fb62931386882a24ebefb8/gistfile1.txt

cf1        worker-001 trace2     RX  Subscribe    3189696406725083   True     False    c668c5d6-e978-45d8-b972-3ecda3e87330   com.example.r1948
cf1        worker-001 trace2     TX  Subscribed   3189696406725083   False    False    c668c5d6-e978-45d8-b972-3ecda3e87330   com.example.r1948
cf1        worker-001 trace2     RX  Publish      8801905038089636   False    False    c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_create
cf1        worker-001 trace2     TX  Event        4320835592887046   False    False    c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_create
cf1        worker-001 trace2     TX  Event        316910278652384    False    True     c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_create
cf1        worker-001 trace2     RX  Publish      8801905038089636   False    True     c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_subscribe
cf1        worker-001 trace2     TX  Event        4320835592887046   False    False    c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_subscribe
cf1        worker-001 trace2     TX  Event        316910278652384    False    True     c668c5d6-e978-45d8-b972-3ecda3e87330   wamp.subscription.on_subscribe
oberstet commented 7 years ago

here is another run: https://gist.githubusercontent.com/oberstet/3128a416e2e733b383c26e4be975b031/raw/9182172d05ea3d10a1002a297721f020f9511f2e/gistfile1.txt

the setup was: 1x CF, 2x WAMP meta API monitor comp., 2x App component

oberstet commented 7 years ago

good thing is, the new correlation_is_last flag is now correct at the app call/publication level:

Call


Node       Worker     Trace      Dir Type         Session            Anchor   Last     Correlation ID                         Correlation URI

................................................................................................................................................................

cf1        worker-001 trace2     RX  Call         6725202028798054   True     False    c7f8025f-6247-41be-844c-f19c603994fe   com.example.add2

cf1        worker-001 trace2     TX  Invocation   1082396409294685   False    False    c7f8025f-6247-41be-844c-f19c603994fe   com.example.add2

cf1        worker-001 trace2     RX  Yield        1082396409294685   False    False    c7f8025f-6247-41be-844c-f19c603994fe   com.example.add2

cf1        worker-001 trace2     TX  Result       6725202028798054   False    True     c7f8025f-6247-41be-844c-f19c603994fe   com.example.add2

Publication


Node       Worker     Trace      Dir Type         Session            Anchor   Last     Correlation ID                         Correlation URI

................................................................................................................................................................

cf1        worker-001 trace2     RX  Publish      6725202028798054   True     False    253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

cf1        worker-001 trace2     TX  Published    6725202028798054   False    False    253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

cf1        worker-001 trace2     TX  Event        2489530629840806   False    False    253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

cf1        worker-001 trace2     TX  Event        1082396409294685   False    False    253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

cf1        worker-001 trace2     TX  Event        6725202028798054   False    False    253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

cf1        worker-001 trace2     TX  Event        7498650488609742   False    True     253ff224-6a4e-48c2-8bff-51ae96737d3c   com.example.oncounter

https://gist.githubusercontent.com/oberstet/a1f1e6e2d9add56f3429a26c26a83e80/raw/16ea93712997863b8c8686cdcf1fa2f796aeb32f/gistfile1.txt

oberstet commented 7 years ago

here is an extensive trace example I get with the current code: https://gist.githubusercontent.com/oberstet/050ce8c9b8b96e01e108a151ebb59f6c/raw/c1848b36de2307d5321bac36b0fdf39c5c10a1bb/gistfile1.txt

this is running 2 CF nodes with multiple app component clients and WAMP meta API clients