So I have modified the config to do the logging you requested, and here is the result: (Note that log entries beginning with "***** " are coming from my class that extends ApplicationSession, so I know the Python path is correct and my class is getting constructed)
scott@solaris:~/Documents/crossbar-tests/pvtest$ crossbar -d start
2014-08-26 15:10:50-0600 [Controller 10367] Log opened.
2014-08-26 15:10:50-0600 [Controller 10367] ============================== Crossbar.io ==============================
2014-08-26 15:10:50-0600 [Controller 10367] Crossbar.io 0.9.7-5 starting
2014-08-26 15:10:50-0600 [Controller 10367] Automatically choosing optimal Twisted reactor
2014-08-26 15:10:52-0600 [Controller 10367] Running Twisted reactor twisted.internet.epollreactor.EPollReactor
2014-08-26 15:10:52-0600 [Controller 10367] Running on CPython using EPollReactor reactor
2014-08-26 15:10:52-0600 [Controller 10367] Starting from node directory /home/scott/Documents/crossbar-tests/pvtest/.crossbar
2014-08-26 15:10:52-0600 [Controller 10367] Starting from local configuration '/home/scott/Documents/crossbar-tests/pvtest/.crossbar/config.json'
2014-08-26 15:10:52-0600 [Controller 10367] No WAMPlets detected in enviroment.
2014-08-26 15:10:52-0600 [Controller 10367] Starting Router with ID 'worker1' ..
2014-08-26 15:10:53-0600 [Router 10376] Log opened.
2014-08-26 15:10:54-0600 [Router 10376] Running under CPython using EPollReactor reactor
2014-08-26 15:10:55-0600 [Router 10376] Entering event loop ..
2014-08-26 15:10:55-0600 [Controller 10367] Router with ID 'worker1' and PID 10376 started
2014-08-26 15:10:55-0600 [Controller 10367] Router 'worker1': PYTHONPATH extended
2014-08-26 15:10:55-0600 [Controller 10367] Router 'worker1': realm 'realm1' started
2014-08-26 15:10:55-0600 [Controller 10367] Router 'worker1': role 'role1' started on realm 'realm1'
2014-08-26 15:10:55-0600 [Router 10376] Site starting on 8080
2014-08-26 15:10:55-0600 [Controller 10367] Router 'worker1': transport 'transport1' started
2014-08-26 15:10:55-0600 [Controller 10367] Starting Container with ID 'worker2' ..
2014-08-26 15:10:55-0600 [Container 10381] Log opened.
2014-08-26 15:10:57-0600 [Container 10381] Running under CPython using EPollReactor reactor
2014-08-26 15:10:57-0600 [Container 10381] Entering event loop ..
2014-08-26 15:10:57-0600 [Controller 10367] Container with ID 'worker2' and PID 10381 started
2014-08-26 15:10:57-0600 [Controller 10367] Container 'worker2': PYTHONPATH extended
2014-08-26 15:11:05-0600 [Container 10381] [('debug', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('debugCodePaths', False, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('logOctets', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('logFrames', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('trackTimings', False, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('allowHixie76', False, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('utf8validateIncoming', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('applyMask', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('maxFramePayloadSize', 0, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('maxMessagePayloadSize', 0, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('autoFragmentSize', 0, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('failByDrop', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('echoCloseCodeReason', False, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('openHandshakeTimeout', 5, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('closeHandshakeTimeout', 1, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('tcpNoDelay', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('autoPingInterval', 0, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('autoPingTimeout', 0, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('autoPingSize', 4, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('version', 18, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('acceptMaskedServerFrames', False, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('maskClientFrames', True, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('serverConnectionDropTimeout', 1, 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('perMessageCompressionOffers', [], 'CrossbarWampWebSocketClientFactory'),
2014-08-26 15:11:05-0600 [Container 10381] ('perMessageCompressionAccept',
2014-08-26 15:11:05-0600 [Container 10381] <function <lambda> at 0x7fe70fe90f50>,
2014-08-26 15:11:05-0600 [Container 10381] 'CrossbarWampWebSocketClientFactory')]
2014-08-26 15:11:05-0600 [Container 10381] connection to
127.0.0.1:8080 established
2014-08-26 15:11:05-0600 [Container 10381] TX Octets to
127.0.0.1:8080 : sync = False, octets = 474554202f777320485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e382e31340d0a486f73743a203132372e302e302e313a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a206a715439307544457956776b534a6b5362644b4268773d3d0d0a5365632d576562536f636b65742d50726f746f636f6c3a2077616d702e322e6d73677061636b2e626174636865642c77616d702e322e6d73677061636b2c77616d702e322e6a736f6e2e626174636865642c77616d702e322e6a736f6e0d0a5365632d576562536f636b65742d56657273696f6e3a2031330d0a0d0a
2014-08-26 15:11:05-0600 [Container 10381] GET /ws HTTP/1.1
2014-08-26 15:11:05-0600 [Container 10381] User-Agent: AutobahnPython/0.8.14
2014-08-26 15:11:05-0600 [Container 10381] Upgrade: WebSocket
2014-08-26 15:11:05-0600 [Container 10381] Connection: Upgrade
2014-08-26 15:11:05-0600 [Container 10381] Pragma: no-cache
2014-08-26 15:11:05-0600 [Container 10381] Cache-Control: no-cache
2014-08-26 15:11:05-0600 [Container 10381] Sec-WebSocket-Key: jqT90uDEyVwkSJkSbdKBhw==
2014-08-26 15:11:05-0600 [Container 10381] Sec-WebSocket-Protocol: wamp.2.msgpack.batched,wamp.2.msgpack,wamp.2.json.batched,wamp.2.json
2014-08-26 15:11:05-0600 [Container 10381] Sec-WebSocket-Version: 13
2014-08-26 15:11:05-0600 [Container 10381] RX Octets from
127.0.0.1:8080 : octets = 485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a2043726f73736261722f302e392e372d350d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d50726f746f636f6c3a2077616d702e322e6d73677061636b2e626174636865640d0a5365632d576562536f636b65742d4163636570743a206959774472486d69684b554d5062683166584c6a4c754c61564d413d0d0a0d0a
2014-08-26 15:11:05-0600 [Container 10381] received HTTP response:
2014-08-26 15:11:05-0600 [Container 10381] HTTP/1.1 101 Switching Protocols
2014-08-26 15:11:05-0600 [Container 10381] Server: Crossbar/0.9.7-5
2014-08-26 15:11:05-0600 [Container 10381] Upgrade: WebSocket
2014-08-26 15:11:05-0600 [Container 10381] Connection: Upgrade
2014-08-26 15:11:05-0600 [Container 10381] Sec-WebSocket-Protocol: wamp.2.msgpack.batched
2014-08-26 15:11:05-0600 [Container 10381] Sec-WebSocket-Accept: iYwDrHmihKUMPbh1fXLjLuLaVMA=
2014-08-26 15:11:05-0600 [Container 10381] received HTTP status line in opening handshake : HTTP/1.1 101 Switching Protocols
2014-08-26 15:11:05-0600 [Container 10381] received HTTP headers in opening handshake : {u'connection': u'Upgrade', u'upgrade': u'WebSocket', u'sec-websocket-protocol': u'wamp.2.msgpack.batched', u'sec-websocket-accept': u'iYwDrHmihKUMPbh1fXLjLuLaVMA=', u'server': u'Crossbar/0.9.7-5'}
2014-08-26 15:11:05-0600 [Container 10381] ***** Inside ServerProtocol constructor
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebStartupRemoteConnection'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebStartupPluginLoader'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebStateLoader'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebFileListing'>
2014-08-26 15:11:05-0600 [Controller 10367] Container 'worker2': component 'component1' started
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebProxyManager'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebColorManager'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebMouseHandler'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebViewPort'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebViewPortImageDelivery'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebViewPortGeometryDelivery'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebTimeHandler'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebSelectionHandler'>
2014-08-26 15:11:05-0600 [Container 10381] ***** Adding protocol to be registered later: <class 'paraview.web.protocols.ParaViewWebWidgetManager'>
2014-08-26 15:11:05-0600 [Container 10381] connection to
127.0.0.1:8080 lost
For completeness, here is the html I'm using to connect from the client side, though I don't think I'm quite getting that far yet :-) Though it connects, it is unable to call the rpc method, which makes sense, because those methods are registered in my onJoin() method, which isn't getting called.