christian-raedel / nightlife-rabbit

A WAMP-Router implementation for node.js
34 stars 8 forks source link

Connection is immediately lost after connect #4

Open RafaelKa opened 9 years ago

RafaelKa commented 9 years ago

I didn't get working your examples and tutorials. All connections with autobahn.js are immediately closed after connect.

My environments: Nodejs: v0.10.36 on Raspbian, v0.12.0 on OsX

PS: with WAMP.rt works all fine.

RafaelKa commented 9 years ago

nightlife-rabbit's router kills publishers connection on "wamp.error.no_such_subscription", is it feature or bug?

christian-raedel commented 9 years ago

Hi,

is Raspbian a amd64 architecture? In my development environment I ran into issues with the native compiled modules, which are used by the underlying websocket implementation ws.

Please figure out, if the test-suite is working on your systems:

make clean install test

Regards, Christian

RafaelKa commented 9 years ago

No, Raspbian is the Debian for Raspberry Pi, also armhf architecture.

I think this is a feature from autobahn.js, that it kills connection on WAMP Protocol errors. WAMP.rt does not response right on publishing in "not subscribed topics" and therefore my code works with WAMP.rt but not with nightlife-rabbit.

If i subscribe first to the topic and then publish in this one all works fine!

But nevertheless i send here output from make clean install test from Raspbian:

************************
* CLEANUP DIRECTORY    *
************************
************************
* INSTALL DEPENDENCIES *
************************

> ws@0.6.5 install /opt/loesche/node_modules/nightlife-rabbit/node_modules/ws
> (node-gyp rebuild 2> builderror.log) || (exit 0)

make[1]: Entering directory `/opt/loesche/node_modules/nightlife-rabbit/node_modules/ws/build'
  CXX(target) Release/obj.target/bufferutil/src/bufferutil.o
  SOLINK_MODULE(target) Release/obj.target/bufferutil.node
  SOLINK_MODULE(target) Release/obj.target/bufferutil.node: Finished
  COPY Release/bufferutil.node
  CXX(target) Release/obj.target/validation/src/validation.o
  SOLINK_MODULE(target) Release/obj.target/validation.node
  SOLINK_MODULE(target) Release/obj.target/validation.node: Finished
  COPY Release/validation.node
make[1]: Leaving directory `/opt/loesche/node_modules/nightlife-rabbit/node_modules/ws/build'
chai-as-promised@4.3.0 node_modules/chai-as-promised

chai-spies@0.5.1 node_modules/chai-spies

q@1.2.0 node_modules/q

debug@2.1.2 node_modules/debug
└── ms@0.7.0

chai@1.10.0 node_modules/chai
├── assertion-error@1.0.0
└── deep-eql@0.1.3 (type-detect@0.1.1)

ws@0.6.5 node_modules/ws
├── options@0.0.6
├── ultron@1.0.1
└── nan@1.4.3

autobahn@0.9.6 node_modules/autobahn
├── when@3.7.2
└── crypto-js@3.1.2-5

lodash@2.4.1 node_modules/lodash

mocha@1.21.5 node_modules/mocha
├── escape-string-regexp@1.0.2
├── diff@1.0.8
├── growl@1.8.1
├── commander@2.3.0
├── debug@2.0.0 (ms@0.6.2)
├── mkdirp@0.5.0 (minimist@0.0.8)
├── glob@3.2.3 (inherits@2.0.1, graceful-fs@2.0.3, minimatch@0.2.14)
└── jade@0.26.3 (commander@0.6.1, mkdirp@0.3.0)

node-cconf@0.3.3 node_modules/node-cconf
└── js-yaml@3.2.7 (esprima@2.0.0, argparse@1.0.1)

node-clogger@0.2.3 node_modules/node-clogger
├── taffydb@2.7.2
├── node-cplate@0.2.0 (colors@0.6.2, debug@1.0.4, moment@2.9.0, node-cconf@0.3.3)
└── node-cconf@0.3.3 (js-yaml@3.2.7)

dna@0.2.7 node_modules/dna
├── colors@0.6.2
├── moment@2.9.0
└── node-cconf@0.3.3 (js-yaml@3.2.7)

jsdoc@3.3.0-beta2 node_modules/jsdoc
├── escape-string-regexp@1.0.3
├── strip-json-comments@1.0.2
├── taffydb@2.6.2
├── underscore@1.7.0
├── async@0.9.0
├── js2xmlparser@0.1.9
├── wrench@1.5.8
├── marked@0.3.3
├── requizzle@0.2.1 (underscore@1.6.0)
├── catharsis@0.8.6 (underscore-contrib@0.3.0)
└── esprima@1.1.0-dev-harmony
************************
* TEST LIBRARY         *
************************
cc:;;;,,,;loooooodd:;;;;;;;::::::::::;;;;,,,,;,;;;,,;,;;;;;;;;;;;;;;;;;;;;;;;;;;;;::;;;;
cc:;;;,,,,loooodddo:;,,,;;;;;;;;;;::::::::::;;;;;;;;;;;;;;;;;;;;;;:::::::::::::::ccc;;;;
lcc:;;,,,,coooodddd:,,,;,;;;;;;;;;;;;;::::::::cclollllllllllllloooooooooooolcccllcc:;;;;
llc:;;,,,,coooodxxd;,,,,;;;;,;;;;;;;;;;;::::::::oxKWWWWWWWNWWWWWNNNNNNNNNNNXXXXOl:c:;;;;
lll:;;;,,,coooddxxd;,,,,,;,,,,;;;;;;;;;;:::;::::oxKMMMMMMMMMWWWWWWWWWWWWWWWWWWNOc::;;;;;
clc:;;,,,,cooodxxxd;,,,,,,,,,,,;;;;;;;;;:;:::::cddKMMMWWWWWNNNXXXXXXXXXXXXXXNNXxc::;;;;;
cclc;;,,,,cooodxkkx;,,,,,,,,,,,;;;;;;;;;;::::::cddXWWWWWWWXK0O0000000000KKKKKXKo:::;;;;;
lllc:;,,,,:ooodxkkx;,,,,,,,,,,,,;;:::;;;;;;::::lkONWWWWWWNKOkkkkkkOOkOOOO0KKKKOc;:;;;;;;
ollcc;,,,,:ooodxxkx;,,,,,,,,,:lx0XNNXKKK0OOOO0KXWWMMMWWWNXKOxxxxxkkkkkkkk0XXXXO:;:;;;;;;
oollc;;,,,:ooodxxkx,',,,,:ldOXNWWWWWNNNWWWWMMMMMMMMMMMMMWX0OkxxxxxxxkxxxxOOkkxo;,:;;;;;;
oollc:;,,,:ooodxkkx,,,cx0NWWWWMWWWWWWWMMMMMMMMMMMMMMMMMMMNXKkdxxxxxxxxxxdkxdooc,;:;;;;;;
doocc:;,,,:ooodxkkx:d0NWWWWWWWWNNNWWWWWWWMMMMMMMMMMMMMMMMWNX0ddxxxxxxxxdddc:::;,;;;;;;;;
dooc:;;,,,:ooddxkO0XNWWWWWWWWWWWWWWWWWWWWWWMMMMMMMMMMMMMMMWNOdxxxxxdxxddoc''',;,;;;;;;;;
dooc:;;,,,:ooddxkKNWWWWWWWWWWWWWWNNNXXXXXK0OOOOOKXNNNWMMMMMWKddddddddddol,....;,:;;;;;;;
xddlc:;;,,:odddxKNWWWWWWWWWWNNNXKOkxolc:;,,,,,;:cllcldkKWMMMWKdooddddoolc. ...;,;;;;;;;;
NNXXK0x:;;cdddx0NWWWWWMWWNKOkxoc:,'........',;;,''''',,ckNMMMW0dooddoool:    ';;;;;;;;;;
MMMMMMXxocldddONWWWWWWWWNOl;'................'.'''''''',ckWMMWN0xooooool;    ,;:;;;;;;;;
MMMMMMWKkoldx0XWWWWWWWNKkc'..........................'''':kWMWNOxdooooll'  ..;,:;;;;;;;;
MMMMMMWXOoldOXWWWWNNNXOo;...............................',l0WWNxoxoooool.  ..;,c;;;;;;;;
MMMMMMWXOolxKNWWWWWNXOo,,.............................''',;l0WWOddololol.   .;,:;;;;;;;;
MMMMMMWX0oldOXWNNNNXOoc;,...............................',;:dNW0xolllloc   .';;;;;;;;;;;
MMMMMMWN0ocokXNXKXN0dlc;,...............................',;;l0WKxollllo:. ..;;;;;:::;;;;
MMMMMMWN0ocokXNXNNXKkdlc,................................',;ckNOdlllloodoodo:;:;;:lo:;;;
MMMMMMWN0ocodOXWWNNXKOd;..................................',:dXklllllox00ooc;;;;:loc;;;;
MMMMMMWN0o:loxXWWWWNNO:................',',''.............',;oOollllldkNNko:;::cloooolc:
MMMMMMMWXkdkkOXWWWNX0o..........';:cldkOOkdoo:'.......,:dO0OkkxlllllldkNXdc;;cccodddxol:
MMMMMMMMMMMMMW0xXWXxc.........,,,,,,;:cclll::;,....,:oOKKKXNNNKollooox0WKlc;:clcllclllc:
MMMMMMMMMMMMMWk';oc,.............'''',:ldddl:'....'oOkxdl::lkX0olllloxKW0oc::cccccclllcc
MMMMMMMMMMMMMMk................',;:;:kXNKxo;......'oxlcoxxxdddollooodkXWX0d::c:::cccllll
WWMMMMMMWWWMMMK'....'...........'',,,;ool:;'.......;dcc0NNN0dlllooodxkKXOkdlooooddddxxxx
ldxdOWWWXNWMMMW:..'..................',,,,,'.......'ldddOOOkdxxkxxkkOOKKxldxdddodddxkkkk
'...'xWMWWMMWWNc.......................'''..........:ollllllONNNNWWWWNWWx:dxkkkxxxddxxxx
O:..'o0WMMMMMWNO'...................................'clcccclKMWWMMMMMWMWklONWWWWNXXXKKKK
KllcdoKWWWMWWWWNO'.'.................................,:::cclKMMMMMMMMMMWkox0XKXXK0KOOkxd
c..,0XWWWMMMWWWWX,...................................';;;::lXWWMMMMMMMMNxlccccclcccc::co
dold0NWMMMMMMMMMWd...................................';;,;:xWMMMMMMMMMWXxdlccoc:::::::cd
NWWMMMMMMMMMMMMMMWx;'........................,c;''..',;;,,cKMMMMMMMMMMMMNKxooOk:::::cccc
WWMMMMMMMMMMMMMMMMMWk...........................'',cc;,,,;dWMMMMMMMMMMMMNX0xodlcc:::::;:
MMMMMMMMMMMMMMMMMMMMX'.......................''',;;ll:;;,:KMMMWNNNWWWMMWNXX0dollccccc:;c
MMMMMMMMWWWWNWWMMMMMX;......................'''';,,colc:;dWMWKxddxkkkOOkk0Kklclllclolc::
MMWWWWNNXK0O0XNWWWWWX,..........................''':cllccXWWOolllllodddxkOOdloc;:::clc:c
MMMMMWWNXKKKXNWWMMMMW;................,:c:::::::codolc::xXXOl:::::codxxkkOKxlll:;;:::ccc
MMMMMMMMMMMMMMMMMMMWK;...............,,,',,,;;::cokOxoc;:c;;:;',,;;;:::cloxxl::ccccccccc
MMMMMMMMMMMMMMWNXKx;................''.....'';::::cccl;';,......'''';:::clcooc:;;;;;;;:c
WMMMMMMMMMMWWKl'..  ...............'''...'',;::c:;::c;'',............',;:clddkOo:::;;;;:
WMMMMMNkccoc;.      ..................'''''''';:cccc:'',....................',:clooolccc
WWNXOl.   ..        ....................''..'',;cllc'.,'........................,:lodoll
kc'...     ..       ........................',,;:c:'.''............................'',cc
....                ...............''...'''',;,;:c;..................  .. ............;:
                    ................''',,,,,,,,;:o,.......   .......          ..........
.         .          ...............''',,,,'',,,cc... ..          ...         . ........
.....     ...        ................''''''''',;c... ..                          ....  .
......    ....        .'.............'''''''',;c' .  ..                           .    .
.......   .....        .;............''...'',;;.    ..                               ...
.......   .....   .     .:,..............'',;,.    ...    ......                        
'......  ......   ..      :l,.............';,...   ..  ............    .              ..
.'.....  ......   ....     'lc'..........',,...   ......,''.........   .              . 
......  .......    .....     'll:,''....','.....  ......:ddddolc:,...  .             ...
 .....  .......  ...  ...      .,::c:;,'.......  ......';o;,;;:cldc.....     .     . ...
 ..... ....'',;,,,'.   ...             ....,cc,.',;,...,cdl....',cd:.... ..       .. .. 
  .......';;,,,,:cc:,.  ...             ...ck0x'd00d...,ldc.....,:dl.... ..       . ..  
    ....';l:,,;:c;;c;,.  ....           ...;d0oxOxoc...,do;....',od:.... .        ...  .
      ..,,c:'',c;;;c;;,  ........       ....xO0k;:c;..,;c',,,,;cddc.......      ....  ..
  .    ',,:c,,;;;;:;,,,. ........      .....olxddkd,..,:c,...'col,........ .............
  .    .'',;;,;;,;:::;,' .........     ...   .;'.,;'..,cl;...',ll,.......'..............
 ...   .'',;,';,'c;,;;,. ..........    ...   ... ......;c,....,:lc.......,..............
 ....   .''';,;''::;:,,............     ..  ....................';:......,'.............
 .....  ...',;,'';:::;.............        .............................'';.............
 ......  .'''''''''','.............       ........................  ....',c,............
AutobahnJS debug enabled

  Router#constructor
[March 8th 2015, 13:17:44] [NightlifeRouter] +   0ms - INFO:    Router option for auto-creating realms is set
[March 8th 2015, 13:17:44] [NightlifeRouter] +  68ms - INFO:    Bound and listen at: 3000
    ✓ should instantiate (90ms)

  Router:Session
[March 8th 2015, 13:17:44] [NightlifeRouter] +  40ms - INFO:    Router option for auto-creating realms is set
[March 8th 2015, 13:17:44] [NightlifeRouter] +   8ms - INFO:    Bound and listen at: 3000
[March 8th 2015, 13:17:44] [NightlifeRouter] + 509ms - INFO:    New realm created com.to.inge.world
trying to create WAMP transport of type: websocket
using WAMP transport type: websocket
[March 8th 2015, 13:17:44] [NightlifeRouter] + 130ms - INFO:    Incoming socket connection
[March 8th 2015, 13:17:45] [NightlifeRouter] +  92ms - DEBUG:   Socket message [1,"com.to.inge.world",{"roles":{"caller":{"features":{"caller_identification":true,"progressive_call_results":true}},"callee":{"features":{"progressive_call_results":true}},"publisher":{"features":{"subscriber_blackwhite_listing":true,"publisher_exclusion":true,"publisher_identification":true}},"subscriber":{"features":{"publisher_identification":true}}}}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +  13ms - DEBUG:   Parsing message { type: 'HELLO',
  realm: 'com.to.inge.world',
  details: 
   { roles: 
      { caller: [Object],
        callee: [Object],
        publisher: [Object],
        subscriber: [Object] } } }
[March 8th 2015, 13:17:45] [NightlifeRouter] +  11ms - DEBUG:   Attaching session to realm com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +  20ms - DEBUG:   Attached session to realm com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +   4ms - DEBUG:   Trying to send message [2, 7094609995890688, {"roles":{"broker":{},"dealer":{}}}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +  11ms - DEBUG:   WELCOME message sent [2, 7094609995890688, {"roles":{"broker":{},"dealer":{}}}]
    ✓ should establish a new session (302ms)
[March 8th 2015, 13:17:45] [NightlifeRouter] +  42ms - DEBUG:   Socket message [6,{},"wamp.close.normal"]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'GOODBYE', details: {}, reason: 'wamp.close.normal' }
[March 8th 2015, 13:17:45] [NightlifeRouter] +   5ms - DEBUG:   Removing session from realm com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +   6ms - DEBUG:   Trying to send message [6, {"message":"Close connection"}, "wamp.error.close_normal"]
[March 8th 2015, 13:17:45] [NightlifeRouter] +  11ms - DEBUG:   GOODBYE message sent [6, {"message":"Close connection"}, "wamp.error.close_normal"]
    ✓ should close a session (75ms)
[March 8th 2015, 13:17:45] [NightlifeRouter] +  42ms - DEBUG:   Socket close 1000 
[March 8th 2015, 13:17:45] [NightlifeRouter] +   3ms - DEBUG:   Removing session from realm com.to.inge.world

  Router:Publish/Subscribe
[March 8th 2015, 13:17:45] [NightlifeRouter] +  24ms - INFO:    Router option for auto-creating realms is set
[March 8th 2015, 13:17:45] [NightlifeRouter] +   6ms - INFO:    Bound and listen at: 3000
trying to create WAMP transport of type: websocket
using WAMP transport type: websocket
[March 8th 2015, 13:17:45] [NightlifeRouter] + 535ms - INFO:    Incoming socket connection
[March 8th 2015, 13:17:45] [NightlifeRouter] +  30ms - DEBUG:   Socket message [1,"com.to.inge.world",{"roles":{"caller":{"features":{"caller_identification":true,"progressive_call_results":true}},"callee":{"features":{"progressive_call_results":true}},"publisher":{"features":{"subscriber_blackwhite_listing":true,"publisher_exclusion":true,"publisher_identification":true}},"subscriber":{"features":{"publisher_identification":true}}}}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   5ms - DEBUG:   Parsing message { type: 'HELLO',
  realm: 'com.to.inge.world',
  details: 
   { roles: 
      { caller: [Object],
        callee: [Object],
        publisher: [Object],
        subscriber: [Object] } } }
[March 8th 2015, 13:17:45] [NightlifeRouter] +   6ms - DEBUG:   Attaching session to realm com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +   3ms - INFO:    New realm created com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +   6ms - DEBUG:   Attached session to realm com.to.inge.world
[March 8th 2015, 13:17:45] [NightlifeRouter] +   3ms - DEBUG:   Trying to send message [2, 2879264456179712, {"roles":{"broker":{},"dealer":{}}}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   8ms - DEBUG:   WELCOME message sent [2, 2879264456179712, {"roles":{"broker":{},"dealer":{}}}]
[March 8th 2015, 13:17:45] [RouterTests] +   0ms - INFO:    Router up and session connected
[March 8th 2015, 13:17:45] [RouterTests] +   7ms - INFO:    Try to subscribe
[March 8th 2015, 13:17:45] [NightlifeRouter] +  46ms - DEBUG:   Socket message [32,4809321846145024,{},"com.example.inge"]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'SUBSCRIBE',
  request: { id: 4809321846145024 },
  options: {},
  topic: 'com.example.inge' }
[March 8th 2015, 13:17:45] [NightlifeRouter] +   5ms - DEBUG:   Try to subscribe to topic: com.example.inge
[March 8th 2015, 13:17:45] [NightlifeRouter] +   8ms - DEBUG:   Trying to send message [33, 4809321846145024, 7609897988390912]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   7ms - DEBUG:   SUBSCRIBED message sent [33, 4809321846145024, 7609897988390912]
[March 8th 2015, 13:17:45] [RouterTests] +  65ms - INFO:    Subscribed to topic
    ✓ should subscribe to a topic (67ms)
[March 8th 2015, 13:17:45] [NightlifeRouter] +  40ms - DEBUG:   Socket message [16,352623374893056,{"acknowledge":true},"com.example.inge",["hello inge!"],{"to":"inge"}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   6ms - DEBUG:   Parsing message { type: 'PUBLISH',
  request: { id: 352623374893056 },
  options: { acknowledge: true },
  topic: 'com.example.inge',
  args: [ 'hello inge!' ],
  kwargs: { to: 'inge' } }
[March 8th 2015, 13:17:45] [NightlifeRouter] +  16ms - DEBUG:   Trying to send message [17, 352623374893056, 6500393169190912]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   4ms - DEBUG:   Trying to send message [36, 7609897988390912, 6500393169190912, {}, ["hello inge!"], {"to":"inge"}]
[March 8th 2015, 13:17:45] [NightlifeRouter] +   3ms - INFO:    Published event to topic com.example.inge
[March 8th 2015, 13:17:45] [NightlifeRouter] +   9ms - DEBUG:   PUBLISHED message sent [17, 352623374893056, 6500393169190912]
[March 8th 2015, 13:17:45] [NightlifeRouter] +  12ms - DEBUG:   EVENT message sent [36, 7609897988390912, 6500393169190912, {}, ["hello inge!"], {"to":"inge"}]
[March 8th 2015, 13:17:46] [RouterTests] +  90ms - INFO:    On event
    ✓ should publish to a topic (505ms)
[March 8th 2015, 13:17:46] [NightlifeRouter] + 461ms - DEBUG:   Socket message [34,7508297833775104,7609897988390912]
[March 8th 2015, 13:17:46] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'UNSUBSCRIBE',
  request: { id: 7508297833775104 },
  subscribed: { subscription: { id: 7609897988390912 } } }
[March 8th 2015, 13:17:46] [NightlifeRouter] +   8ms - DEBUG:   Trying to send message [35, 7508297833775104]
[March 8th 2015, 13:17:46] [NightlifeRouter] +   8ms - DEBUG:   UNSUBSCRIBED message sent [35, 7508297833775104]
    ✓ should unsubscribe from a topic (50ms)
[March 8th 2015, 13:17:46] [NightlifeRouter] +  27ms - DEBUG:   Removing session from realm com.to.inge.world
[March 8th 2015, 13:17:46] [NightlifeRouter] +   5ms - DEBUG:   Trying to send message [6, {"message":"Close connection"}, "wamp.error.system_shutdown"]
[March 8th 2015, 13:17:46] [NightlifeRouter] +   3ms - DEBUG:   GOODBYE message sent [6, {"message":"Close connection"}, "wamp.error.system_shutdown"]

  Router:Remote Procedures
[March 8th 2015, 13:17:46] [NightlifeRouter] +  10ms - INFO:    Router option for auto-creating realms is set
[March 8th 2015, 13:17:46] [NightlifeRouter] +   5ms - INFO:    Bound and listen at: 3000
[March 8th 2015, 13:17:46] [NightlifeRouter] +  11ms - DEBUG:   Socket close 1000 
[March 8th 2015, 13:17:46] [NightlifeRouter] +   3ms - DEBUG:   Removing session from realm com.to.inge.world
trying to create WAMP transport of type: websocket
using WAMP transport type: websocket
[March 8th 2015, 13:17:47] [NightlifeRouter] + 510ms - INFO:    Incoming socket connection
[March 8th 2015, 13:17:47] [NightlifeRouter] +  31ms - DEBUG:   Socket message [1,"com.to.inge.world",{"roles":{"caller":{"features":{"caller_identification":true,"progressive_call_results":true}},"callee":{"features":{"progressive_call_results":true}},"publisher":{"features":{"subscriber_blackwhite_listing":true,"publisher_exclusion":true,"publisher_identification":true}},"subscriber":{"features":{"publisher_identification":true}}}}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   3ms - DEBUG:   Parsing message { type: 'HELLO',
  realm: 'com.to.inge.world',
  details: 
   { roles: 
      { caller: [Object],
        callee: [Object],
        publisher: [Object],
        subscriber: [Object] } } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   5ms - DEBUG:   Attaching session to realm com.to.inge.world
[March 8th 2015, 13:17:47] [NightlifeRouter] +   3ms - INFO:    New realm created com.to.inge.world
[March 8th 2015, 13:17:47] [NightlifeRouter] +   5ms - DEBUG:   Attached session to realm com.to.inge.world
[March 8th 2015, 13:17:47] [NightlifeRouter] +   3ms - DEBUG:   Trying to send message [2, 6073419795791872, {"roles":{"broker":{},"dealer":{}}}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   9ms - DEBUG:   WELCOME message sent [2, 6073419795791872, {"roles":{"broker":{},"dealer":{}}}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +  32ms - DEBUG:   Socket message [64,6781468414050304,{},"com.example.inge"]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   3ms - DEBUG:   Parsing message { type: 'REGISTER',
  request: { id: 6781468414050304 },
  options: {},
  procedure: 'com.example.inge' }
[March 8th 2015, 13:17:47] [NightlifeRouter] +  11ms - DEBUG:   Trying to send message [65, 6781468414050304, 8195278154760192]
[March 8th 2015, 13:17:47] [NightlifeRouter] +  11ms - DEBUG:   REGISTERED message sent [65, 6781468414050304, 8195278154760192]
    ✓ should register a remote procedure (53ms)
[March 8th 2015, 13:17:47] [NightlifeRouter] +  35ms - DEBUG:   Socket message [48,2991618340683776,{},"com.example.inge",["hello inge!"],{"to":"inge"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'CALL',
  request: { id: 2991618340683776 },
  options: {},
  procedure: 'com.example.inge',
  args: [ 'hello inge!' ],
  kwargs: { to: 'inge' } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   9ms - DEBUG:   Trying to send message [68, 4820147208454144, 8195278154760192, {}, ["hello inge!"], {"to":"inge"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   7ms - DEBUG:   INVOCATION message sent [68, 4820147208454144, 8195278154760192, {}, ["hello inge!"], {"to":"inge"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +  29ms - DEBUG:   Socket message [70,4820147208454144,{},["inge"]]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'YIELD',
  invocation: { request: { id: 4820147208454144 } },
  options: {},
  args: [ 'inge' ],
  kwargs: {} }
[March 8th 2015, 13:17:47] [NightlifeRouter] +  10ms - DEBUG:   Trying to send message [50, 2991618340683776, {}, ["inge"], ""]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   6ms - DEBUG:   RESULT message sent [50, 2991618340683776, {}, ["inge"], ""]
    ✓ should call a remote procedure (98ms)
[March 8th 2015, 13:17:47] [NightlifeRouter] +  31ms - DEBUG:   Socket message [48,7257586768281600,{},"com.example.inge",["hello inge!"],{"to":"world"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   7ms - DEBUG:   Parsing message { type: 'CALL',
  request: { id: 7257586768281600 },
  options: {},
  procedure: 'com.example.inge',
  args: [ 'hello inge!' ],
  kwargs: { to: 'world' } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   8ms - DEBUG:   Trying to send message [68, 7084903923449856, 8195278154760192, {}, ["hello inge!"], {"to":"world"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   6ms - DEBUG:   INVOCATION message sent [68, 7084903923449856, 8195278154760192, {}, ["hello inge!"], {"to":"world"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +  23ms - DEBUG:   Socket message [8,68,7084903923449856,{},"com.example.inge.error",["hello inge!"],{"to":"world"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   4ms - DEBUG:   Parsing message { type: 'ERROR',
  request: { type: 68, id: 7084903923449856 },
  details: {},
  error: 'com.example.inge.error',
  args: [ 'hello inge!' ],
  kwargs: { to: 'world' } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   4ms - ERROR:   Trying to send error message for: { type: 'ERROR',
  request: { type: 68, id: 7084903923449856 },
  details: {},
  error: 'com.example.inge.error',
  args: [ 'hello inge!' ],
  kwargs: { to: 'world' } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   7ms - DEBUG:   Trying to send message [8, 48, 7257586768281600, {}, "com.example.inge.error", ["hello inge!"], {"to":"world"}]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   6ms - DEBUG:   ERROR message sent [8, 48, 7257586768281600, {}, "com.example.inge.error", ["hello inge!"], {"to":"world"}]
    ✓ should return an error, if remote procedure throws (91ms)
[March 8th 2015, 13:17:47] [NightlifeRouter] +  33ms - DEBUG:   Socket message [66,698161517559808,8195278154760192]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   7ms - DEBUG:   Parsing message { type: 'UNREGISTER',
  request: { id: 698161517559808 },
  registered: { registration: { id: 8195278154760192 } } }
[March 8th 2015, 13:17:47] [NightlifeRouter] +   6ms - DEBUG:   Trying to send message [67, 698161517559808]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   6ms - DEBUG:   UNREGISTERED message sent [67, 698161517559808]
    ✓ should unregister a remote procedure (44ms)
[March 8th 2015, 13:17:47] [NightlifeRouter] +  22ms - DEBUG:   Removing session from realm com.to.inge.world
[March 8th 2015, 13:17:47] [NightlifeRouter] +   5ms - DEBUG:   Trying to send message [6, {"message":"Close connection"}, "wamp.error.system_shutdown"]
[March 8th 2015, 13:17:47] [NightlifeRouter] +   2ms - DEBUG:   GOODBYE message sent [6, {"message":"Close connection"}, "wamp.error.system_shutdown"]

  10 passing (3s)