Connection aborted when trying to sendMessage() "failure with no frames"/twisted.internet.error.connectionAborted

#1

Hi all,

I’m trying to set up a simple bit of communication between my Python WS client, and a server that is processing and responding to particular Json requests.

Using another Python websocket client, I send a Json request like so:

{‘type’ : ‘INITIALISE’}

and get a Json response:

{‘type’ : ‘INITIALISATION SUCCESS’}

as expected. When I try to use Autobahn I get the following error as soon as I try to call sendMessage():

[Failure instance: Traceback (failure with no frames): <class ‘twisted.internet.error.ConnectionAborted’>:

Connection was aborted locally, using

L{twisted.internet.interfaces.ITCPTransport.abortConnection}.

@since: 11.1

.]

My WS URI looks something like: " ws://[ip:port]/gateway/websocketcall?sessionID=xxxxx "

Code is below. Does anyone know why this may be happening? Thanks. I’m running on Python 2.7, Ubuntu 12.10 64-bit, Twisted 12.1.0.

Many thanks

class RequestTestClient(WebSocketClientProtocol):

def onMessage(self, message, binary):

    print "Received message: " + message 

    #reactor.callLater(self.processMessage(message)) #@UndefinedVariable



def connectionLost(self, reason):

    print "Connection lost: " + str(reason)

    

def onClose(self):

    print "Closing connection"



def onOpen(self):

    print "Connection opened"

    self.send_initialise()            

    

def send_initialise(self):    

    msg = json.dumps({

                          'type':'INITIALISE',

                          })

    print "Sending INITIALISE message..."

    self.sendMessage(msg)

    print "INITIALISE sent."

def doLoginAndGetSessionInformation():

[...]

def decodeSessionIdAndGetWsUri(sessionId):

[...]

if name==‘main’:

wsUri = decodeSessionIdAndGetWsUri(json.loads(doLoginAndGetSessionInformation())['sessionid'])

print wsUri

wsFactory = WebSocketClientFactory(url=wsUri, debug = True)

wsFactory.protocol = RequestTestClient

connectWS(wsFactory)



reactor.run() #@UndefinedVariable
0 Likes

#2

Thomas,

could you attach the complete log from Autobahn (with debug = True ..as you already do)?

What server are you using?

Tobias

···

Am 13.03.2013 12:44, schrieb Thomas Madhavan:

Hi all,

I'm trying to set up a simple bit of communication between my Python WS
client, and a server that is processing and responding to particular
Json requests.

Using another Python websocket client, I send a Json request like so:

{'type' : 'INITIALISE'}

and get a Json response:

{'type' : 'INITIALISATION SUCCESS'}

as expected. When I try to use Autobahn I get the following error as
soon as I try to call sendMessage():

[Failure instance: Traceback (failure with no frames): <class
'twisted.internet.error.ConnectionAborted'>:
     Connection was aborted locally, using
     L{twisted.internet.interfaces.ITCPTransport.abortConnection}.

     @since: 11.1
.]

My WS URI looks something like:
" ws://[ip:port]/gateway/websocketcall?sessionID=xxxxx "

Code is below. Does anyone know why this may be happening? Thanks. I'm
running on Python 2.7, Ubuntu 12.10 64-bit, Twisted 12.1.0.

Many thanks

class RequestTestClient(WebSocketClientProtocol):
     def onMessage(self, message, binary):
         print "Received message: " + message
         #reactor.callLater(self.processMessage(message))
#@UndefinedVariable
     def connectionLost(self, reason):
         print "Connection lost: " + str(reason)
     def onClose(self):
         print "Closing connection"
     def onOpen(self):
         print "Connection opened"
         self.send_initialise()
     def send_initialise(self):
         msg = json.dumps({
                               'type':'INITIALISE',
                               })

         print "Sending INITIALISE message..."
         self.sendMessage(msg)
         print "INITIALISE sent."

def doLoginAndGetSessionInformation():
     [...]

def decodeSessionIdAndGetWsUri(sessionId):
     [...]

if __name__=='__main__':
     wsUri =
decodeSessionIdAndGetWsUri(json.loads(doLoginAndGetSessionInformation())['sessionid'])
     print wsUri
     wsFactory = WebSocketClientFactory(url=wsUri, debug = True)
     wsFactory.protocol = RequestTestClient

     connectWS(wsFactory)
     reactor.run() #@UndefinedVariable

--
You received this message because you are subscribed to the Google
Groups "Autobahn" group.
To unsubscribe from this group and stop receiving emails from it, send
an email to autobahnws+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

0 Likes

#3

Hello,

Using twisted.python logger, the full log is shown below:

2013-03-18 07:29:12+0000 [-] Log opened.

2013-03-18 07:29:12+0000 [-] ws://192.168.13.50:8080/gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7

2013-03-18 07:29:12+0000 [-] Starting factory <autobahn.websocket.WebSocketClientFactory instance at 0x2888878>

2013-03-18 07:29:12+0000 [Uninitialized] connection to 192.168.13.50:8080 established

2013-03-18 07:29:12+0000 [Uninitialized] GET /gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7 HTTP/1.1

User-Agent: AutobahnPython/0.5.14

Host: 192.168.13.50:8080

Upgrade: WebSocket

Connection: Upgrade

Pragma: no-cache

Cache-Control: no-cache

Sec-WebSocket-Key: 4Td1vPwY2/B4FkAk2iAEcg==

Sec-WebSocket-Version: 8

2013-03-18 07:29:12+0000 [Uninitialized] TX Octets to 192.168.13.50:8080 : sync = False, octets = 474554202f676174657761792f776562736f636b657463616c6c3f73657373696f6e49443d32313864643731392d343236392d343138312d613335662d37333538633130616362613720485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e352e31340d0a486f73743a203139322e3136382e31332e35303a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a203454643176507759322f4234466b416b3269414563673d3d0d0a5365632d576562536f636b65742d56657273696f6e3a20380d0a0d0a

2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d436f796f74652f312e310d0a5365742d436f6f6b69653a204a53455353494f4e49443d3463654b4b6d55696e6e5263424475494c563571444836763b20506174683d2f676174657761790d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d4c6f636174696f6e3a2077733a2f2f3139322e3136382e31332e35303a383038302f676174657761792f776562736f636b657463616c6c0d0a5365632d576562536f636b65742d4163636570743a20774e384a5853585166634646366643334e37575731664b754c78513d0d0a446174653a204d6f6e2c203138204d617220323031332030373a32393a313320474d540d0a0d0a

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP response:

HTTP/1.1 101 Switching Protocols

Server: Apache-Coyote/1.1

Set-Cookie: JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway

Upgrade: WebSocket

Connection: Upgrade

Sec-WebSocket-Location: ws://192.168.13.50:8080/gateway/websocketcall

Sec-WebSocket-Accept: wN8JXSXQfcFF6fC3N7WW1fKuLxQ=

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP status line in opening handshake : HTTP/1.1 101 Switching Protocols

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP headers in opening handshake : {‘upgrade’: u’WebSocket’, ‘sec-websocket-accept’: u’wN8JXSXQfcFF6fC3N7WW1fKuLxQ=’, ‘set-cookie’: u’JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway’, ‘server’: u’Apache-Coyote/1.1’, ‘connection’: u’Upgrade’, ‘sec-websocket-location’: u’ws://192.168.13.50:8080/gateway/websocketcall’, ‘date’: u’Mon, 18 Mar 2013 07:29:13 GMT’}

2013-03-18 07:29:12+0000 [RequestTestClient,client] Connection opened

2013-03-18 07:29:12+0000 [RequestTestClient,client] Starting SWIFT initialisation…

2013-03-18 07:29:12+0000 [RequestTestClient,client] Sending INITIALISE message…

2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Frame to 192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 9382cbdc, length = 22, repeat_length = None, chopsize = None, sync = False, payload = {“type”: “INITIALISE”}

2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Octets to 192.168.13.50:8080 : sync = False, octets = 81969382cbdce8a0bfa5e3e7e9e6b3a08292dad6829ddfcb9899b1ff

2013-03-18 07:29:12+0000 [RequestTestClient,client] INITIALISE sent.

2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 81a1402f781c3b0d0c65304a5a266266365514663950097c394809603643137a3b5f057c2b3e3d

2013-03-18 07:29:12+0000 [-] Connection lost: [Failure instance: Traceback (failure with no frames): <class ‘twisted.internet.error.ConnectionAborted’>:

2013-03-18 07:29:12+0000 [-] Connection was aborted locally, using

2013-03-18 07:29:12+0000 [-] L{twisted.internet.interfaces.ITCPTransport.abortConnection}.

2013-03-18 07:29:12+0000 [-]

2013-03-18 07:29:12+0000 [-] @since: 11.1

2013-03-18 07:29:12+0000 [-] .

2013-03-18 07:29:12+0000 [-] ]

2013-03-18 07:29:12+0000 [-] Stopping factory <autobahn.websocket.WebSocketClientFactory instance at 0x2888878>

The server being used is an in house Java application server, running on JBoss AS 7. I’m not sure which Java WS library is being used, or if it has been written from scratch.

Thom

···

Date: Mon, 18 Mar 2013 07:29:13 GMT

On Saturday, March 16, 2013 9:40:14 AM UTC, Tobias Oberstein wrote:

Thomas,

could you attach the complete log from Autobahn (with debug = True …as
you already do)?

What server are you using?

Tobias

Am 13.03.2013 12:44, schrieb Thomas Madhavan:

Hi all,

I’m trying to set up a simple bit of communication between my Python WS

client, and a server that is processing and responding to particular

Json requests.

Using another Python websocket client, I send a Json request like so:

{‘type’ : ‘INITIALISE’}

and get a Json response:

{‘type’ : ‘INITIALISATION SUCCESS’}

as expected. When I try to use Autobahn I get the following error as

soon as I try to call sendMessage():

[Failure instance: Traceback (failure with no frames): <class

‘twisted.internet.error.ConnectionAborted’>:

 Connection was aborted locally, using
 L{twisted.internet.interfaces.ITCPTransport.abortConnection}.
 @since: 11.1

.]

My WS URI looks something like:

" ws://[ip:port]/gateway/websocketcall?sessionID=xxxxx "

Code is below. Does anyone know why this may be happening? Thanks. I’m

running on Python 2.7, Ubuntu 12.10 64-bit, Twisted 12.1.0.

Many thanks

class RequestTestClient(WebSocketClientProtocol):

 def onMessage(self, message, binary):
     print "Received message: " + message
     #reactor.callLater(self.processMessage(message))

#@UndefinedVariable

 def connectionLost(self, reason):
     print "Connection lost: " + str(reason)
 def onClose(self):
     print "Closing connection"
 def onOpen(self):
     print "Connection opened"
     self.send_initialise()
 def send_initialise(self):
     msg = json.dumps({
                           'type':'INITIALISE',
                           })
     print "Sending INITIALISE message..."
     self.sendMessage(msg)
     print "INITIALISE sent."

def doLoginAndGetSessionInformation():

 [...]

def decodeSessionIdAndGetWsUri(sessionId):

 [...]

if name==‘main’:

 wsUri =

decodeSessionIdAndGetWsUri(json.loads(doLoginAndGetSessionInformation())[‘sessionid’])

 print wsUri
 wsFactory = WebSocketClientFactory(url=wsUri, debug = True)
 wsFactory.protocol = RequestTestClient
 connectWS(wsFactory)
 reactor.run() #@UndefinedVariable

You received this message because you are subscribed to the Google

Groups “Autobahn” group.

To unsubscribe from this group and stop receiving emails from it, send

an email to autobahnws+...@googlegroups.com.

For more options, visit https://groups.google.com/groups/opt_out.

0 Likes

#4

Thomas,

sorry (forgot), could you please set both

debug = True, debugCodePaths = True

WebSocketClientFactory and resend your log output?

I suspect there might be a protocol violation triggering the immediate drop of connection when receiving the first WS message from server.

You can also control that behavior by setting

setProtocolOptions(failByDrop = False)

on your factory.

Tobias

···

Am 18.03.2013 08:31, schrieb Thomas Madhavan:

Hello,

Using twisted.python logger, the full log is shown below:

2013-03-18 07:29:12+0000 [-] Log opened.
2013-03-18 07:29:12+0000 [-]
ws://192.168.13.50:8080/gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7
2013-03-18 07:29:12+0000 [-] Starting factory
<autobahn.websocket.WebSocketClientFactory instance at 0x2888878>
2013-03-18 07:29:12+0000 [Uninitialized] connection to
192.168.13.50:8080 established
2013-03-18 07:29:12+0000 [Uninitialized] GET
/gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7
HTTP/1.1
User-Agent: AutobahnPython/0.5.14
Host: 192.168.13.50:8080
Upgrade: WebSocket
Connection: Upgrade
Pragma: no-cache
Cache-Control: no-cache
Sec-WebSocket-Key: 4Td1vPwY2/B4FkAk2iAEcg==
Sec-WebSocket-Version: 8
2013-03-18 07:29:12+0000 [Uninitialized] TX Octets to 192.168.13.50:8080
: sync = False, octets =
474554202f676174657761792f776562736f636b657463616c6c3f73657373696f6e49443d32313864643731392d343236392d343138312d613335662d37333538633130616362613720485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e352e31340d0a486f73743a203139322e3136382e31332e35303a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a203454643176507759322f4234466b416b3269414563673d3d0d0a5365632d576562536f636b65742d56657273696f6e3a20380d0a0d0a
2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from
192.168.13.50:8080 : octets =
485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d436f796f74652f312e310d0a5365742d436f6f6b69653a204a53455353494f4e49443d3463654b4b6d55696e6e5263424475494c563571444836763b20506174683d2f676174657761790d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d4c6f636174696f6e3a2077733a2f2f3139322e3136382e31332e35303a383038302f676174657761792f776562736f636b657463616c6c0d0a5365632d576562536f636b65742d4163636570743a20774e384a5853585166634646366643334e37575731664b754c78513d0d0a446174653a204d6f6e2c203138204d617220323031332030373a32393a313320474d540d0a0d0a
2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP response:
HTTP/1.1 101 Switching Protocols
Server: Apache-Coyote/1.1
Set-Cookie: JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway
Upgrade: WebSocket
Connection: Upgrade
Sec-WebSocket-Location: ws://192.168.13.50:8080/gateway/websocketcall
Sec-WebSocket-Accept: wN8JXSXQfcFF6fC3N7WW1fKuLxQ=
Date: Mon, 18 Mar 2013 07:29:13 GMT
2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP status
line in opening handshake : HTTP/1.1 101 Switching Protocols
2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP
headers in opening handshake : {'upgrade': u'WebSocket',
'sec-websocket-accept': u'wN8JXSXQfcFF6fC3N7WW1fKuLxQ=', 'set-cookie':
u'JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway', 'server':
u'Apache-Coyote/1.1', 'connection': u'Upgrade',
'sec-websocket-location':
u'ws://192.168.13.50:8080/gateway/websocketcall', 'date': u'Mon, 18 Mar
2013 07:29:13 GMT'}
2013-03-18 07:29:12+0000 [RequestTestClient,client] Connection opened
2013-03-18 07:29:12+0000 [RequestTestClient,client] Starting SWIFT
initialisation...
2013-03-18 07:29:12+0000 [RequestTestClient,client] Sending INITIALISE
message...
2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Frame to
192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 9382cbdc,
length = 22, repeat_length = None, chopsize = None, sync = False,
payload = {"type": "INITIALISE"}
2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Octets to
192.168.13.50:8080 : sync = False, octets =
81969382cbdce8a0bfa5e3e7e9e6b3a08292dad6829ddfcb9899b1ff
2013-03-18 07:29:12+0000 [RequestTestClient,client] INITIALISE sent.
2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from
192.168.13.50:8080 : octets =
81a1402f781c3b0d0c65304a5a266266365514663950097c394809603643137a3b5f057c2b3e3d
2013-03-18 07:29:12+0000 [-] Connection lost: [Failure instance:
Traceback (failure with no frames): <class
'twisted.internet.error.ConnectionAborted'>:
2013-03-18 07:29:12+0000 [-] Connection was aborted locally, using
2013-03-18 07:29:12+0000 [-]
L{twisted.internet.interfaces.ITCPTransport.abortConnection}.
2013-03-18 07:29:12+0000 [-]
2013-03-18 07:29:12+0000 [-] @since: 11.1
2013-03-18 07:29:12+0000 [-] .
2013-03-18 07:29:12+0000 [-] ]
2013-03-18 07:29:12+0000 [-] Stopping factory
<autobahn.websocket.WebSocketClientFactory instance at 0x2888878>

The server being used is an in house Java application server, running on
JBoss AS 7. I'm not sure which Java WS library is being used, or if it
has been written from scratch.

Thom

On Saturday, March 16, 2013 9:40:14 AM UTC, Tobias Oberstein wrote:

    Thomas,

    could you attach the complete log from Autobahn (with debug = True ..as
    you already do)?

    What server are you using?

    Tobias

    Am 13.03.2013 12:44, schrieb Thomas Madhavan:
     > Hi all,
     >
     > I'm trying to set up a simple bit of communication between my
    Python WS
     > client, and a server that is processing and responding to particular
     > Json requests.
     >
     > Using another Python websocket client, I send a Json request like
    so:
     >
     > {'type' : 'INITIALISE'}
     >
     > and get a Json response:
     >
     > {'type' : 'INITIALISATION SUCCESS'}
     >
     > as expected. When I try to use Autobahn I get the following error as
     > soon as I try to call sendMessage():
     >
     > [Failure instance: Traceback (failure with no frames): <class
     > 'twisted.internet.error.ConnectionAborted'>:
     > Connection was aborted locally, using
     > L{twisted.internet.interfaces.ITCPTransport.abortConnection}.
     >
     > @since: 11.1
     > .]
     >
     > My WS URI looks something like:
     > " ws://[ip:port]/gateway/websocketcall?sessionID=xxxxx "
     >
     > Code is below. Does anyone know why this may be happening?
    Thanks. I'm
     > running on Python 2.7, Ubuntu 12.10 64-bit, Twisted 12.1.0.
     >
     > Many thanks
     >
     > class RequestTestClient(WebSocketClientProtocol):
     > def onMessage(self, message, binary):
     > print "Received message: " + message
     > #reactor.callLater(self.processMessage(message))
     > #@UndefinedVariable
     > def connectionLost(self, reason):
     > print "Connection lost: " + str(reason)
     > def onClose(self):
     > print "Closing connection"
     > def onOpen(self):
     > print "Connection opened"
     > self.send_initialise()
     > def send_initialise(self):
     > msg = json.dumps({
     > 'type':'INITIALISE',
     > })
     >
     > print "Sending INITIALISE message..."
     > self.sendMessage(msg)
     > print "INITIALISE sent."
     >
     > def doLoginAndGetSessionInformation():
     > [...]
     >
     > def decodeSessionIdAndGetWsUri(sessionId):
     > [...]
     >
     > if __name__=='__main__':
     > wsUri =
     >
    decodeSessionIdAndGetWsUri(json.loads(doLoginAndGetSessionInformation())['sessionid'])

     > print wsUri
     > wsFactory = WebSocketClientFactory(url=wsUri, debug = True)
     > wsFactory.protocol = RequestTestClient
     >
     > connectWS(wsFactory)
     > reactor.run() #@UndefinedVariable
     >
     > --
     > You received this message because you are subscribed to the Google
     > Groups "Autobahn" group.
     > To unsubscribe from this group and stop receiving emails from it,
    send
     > an email to autobah...@googlegroups.com <javascript:>.
     > For more options, visit https://groups.google.com/groups/opt_out
    <https://groups.google.com/groups/opt_out>.
     >

--
You received this message because you are subscribed to the Google
Groups "Autobahn" group.
To unsubscribe from this group and stop receiving emails from it, send
an email to autobahnws+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

0 Likes

#5

Hello,

Thank you for your reply, and time. I have repeated the run with debugCodePaths enabled, with the following similar results:

2013-03-18 17:01:02+0000 [-] Log opened.

2013-03-18 17:01:02+0000 [-] ws://192.168.13.50:8080/gateway/websocketcall?sessionID=FWGW-30623611-7bad-4f74-aeb3-08835d27c5ff

2013-03-18 17:01:02+0000 [-] Starting factory <autobahn.websocket.WebSocketClientFactory instance at 0x29fb878>

2013-03-18 17:01:02+0000 [Uninitialized] connection to 192.168.13.50:8080 established

2013-03-18 17:01:02+0000 [Uninitialized] GET /gateway/websocketcall?sessionID=FWGW-30623611-7bad-4f74-aeb3-08835d27c5ff HTTP/1.1

User-Agent: AutobahnPython/0.5.14

Host: 192.168.13.50:8080

Upgrade: WebSocket

Connection: Upgrade

Pragma: no-cache

Cache-Control: no-cache

Sec-WebSocket-Key: sA6wY6UHlYAtAKcZSPjGbQ==

Sec-WebSocket-Version: 8

2013-03-18 17:01:02+0000 [Uninitialized] TX Octets to 192.168.13.50:8080 : sync = False, octets = 474554202f676174657761792f776562736f636b657463616c6c3f73657373696f6e49443d465747572d33303632333631312d376261642d346637342d616562332d30383833356432376335666620485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e352e31340d0a486f73743a203139322e3136382e31332e35303a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a2073413677593655486c594174414b635a53506a4762513d3d0d0a5365632d576562536f636b65742d56657273696f6e3a20380d0a0d0a

2013-03-18 17:01:02+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d436f796f74652f312e310d0a5365742d436f6f6b69653a204a53455353494f4e49443d5776754953685756445362615338765565525937362b754a3b20506174683d2f676174657761790d0a4163636573732d436f6e74726f6c2d416c6c6f772d486561646572733a20636f6e74656e742d747970650d0a4163636573732d436f6e74726f6c2d416c6c6f772d43726564656e7469616c733a20747275650d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d4c6f636174696f6e3a2077733a2f2f3139322e3136382e31332e35303a383038302f676174657761792f776562736f636b657463616c6c0d0a5365632d576562536f636b65742d4163636570743a204f647a364b527177482b6a4d7342466a6c4c4771576d50382b2b673d0d0a446174653a204d6f6e2c203138204d617220323031332031373a30313a303320474d540d0a0d0a

2013-03-18 17:01:02+0000 [RequestTestClient,client] received HTTP response:

HTTP/1.1 101 Switching Protocols

Server: Apache-Coyote/1.1

Set-Cookie: JSESSIONID=WvuIShWVDSbaS8vUeRY76+uJ; Path=/gateway

Access-Control-Allow-Headers: content-type

Access-Control-Allow-Credentials: true

Upgrade: WebSocket

Connection: Upgrade

Sec-WebSocket-Location: ws://192.168.13.50:8080/gateway/websocketcall

Sec-WebSocket-Accept: Odz6KRqwH+jMsBFjlLGqWmP8++g=
···

Date: Mon, 18 Mar 2013 17:01:03 GMT

2013-03-18 17:01:02+0000 [RequestTestClient,client] received HTTP status line in opening handshake : HTTP/1.1 101 Switching Protocols

2013-03-18 17:01:02+0000 [RequestTestClient,client] received HTTP headers in opening handshake : {‘upgrade’: u’WebSocket’, ‘sec-websocket-accept’: u’Odz6KRqwH+jMsBFjlLGqWmP8++g=’, ‘set-cookie’: u’JSESSIONID=WvuIShWVDSbaS8vUeRY76+uJ; Path=/gateway’, ‘server’: u’Apache-Coyote/1.1’, ‘connection’: u’Upgrade’, ‘access-control-allow-credentials’: u’true’, ‘date’: u’Mon, 18 Mar 2013 17:01:03 GMT’, ‘access-control-allow-headers’: u’content-type’, ‘sec-websocket-location’: u’ws://192.168.13.50:8080/gateway/websocketcall’}

2013-03-18 17:01:02+0000 [RequestTestClient,client] Connection opened

2013-03-18 17:01:02+0000 [RequestTestClient,client] Starting SWIFT initialisation…

2013-03-18 17:01:02+0000 [RequestTestClient,client] Sending INITIALISE message…

2013-03-18 17:01:02+0000 [RequestTestClient,client] TX Frame to 192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 73f357db, length = 22, repeat_length = None, chopsize = None, sync = False, payload = {“type”: “INITIALISE”}

2013-03-18 17:01:02+0000 [RequestTestClient,client] TX Octets to 192.168.13.50:8080 : sync = False, octets = 819673f357db08d123a2039675e153d11e953aa71e9a3fba049e518e

2013-03-18 17:01:02+0000 [RequestTestClient,client] INITIALISE sent.

2013-03-18 17:01:02+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 81a3031ff4b55864d6c17a6f9197393dbdfb4a4bbdf44f56a7f45756bbfb5c4ca1f6405aa7e62162a9

2013-03-18 17:01:02+0000 [RequestTestClient,client] Protocol violation : masked server-to-client frame

2013-03-18 17:01:02+0000 [RequestTestClient,client] Failing connection : 1002 - masked server-to-client frame

2013-03-18 17:01:02+0000 [RequestTestClient,client] dropping connection

2013-03-18 17:01:02+0000 [-] Connection lost: [Failure instance: Traceback (failure with no frames): <class ‘twisted.internet.error.ConnectionAborted’>:

2013-03-18 17:01:02+0000 [-] Connection was aborted locally, using

2013-03-18 17:01:02+0000 [-] L{twisted.internet.interfaces.ITCPTransport.abortConnection}.

2013-03-18 17:01:02+0000 [-]

2013-03-18 17:01:02+0000 [-] @since: 11.1

2013-03-18 17:01:02+0000 [-] .

2013-03-18 17:01:02+0000 [-] ]

2013-03-18 17:01:02+0000 [-] Stopping factory <autobahn.websocket.WebSocketClientFactory instance at 0x29fb878>

2013-03-18 17:01:07+0000 [-] skipping onOpenHandshakeTimeout since WebSocket connection already closed

Attempting to set failByDrop=False results in similar results:

2013-03-18 17:03:51+0000 [-] Log opened.

2013-03-18 17:03:51+0000 [-] ws://192.168.13.50:8080/gateway/websocketcall?sessionID=FWGW-770cce81-36e5-4576-bfe6-3db4ca38bd21

2013-03-18 17:03:51+0000 [-] Starting factory <autobahn.websocket.WebSocketClientFactory instance at 0x229d878>

2013-03-18 17:03:51+0000 [Uninitialized] connection to 192.168.13.50:8080 established

2013-03-18 17:03:51+0000 [Uninitialized] GET /gateway/websocketcall?sessionID=FWGW-770cce81-36e5-4576-bfe6-3db4ca38bd21 HTTP/1.1

User-Agent: AutobahnPython/0.5.14

Host: 192.168.13.50:8080

Upgrade: WebSocket

Connection: Upgrade

Pragma: no-cache

Cache-Control: no-cache

Sec-WebSocket-Key: BscBDJ+G8fBKS5S6RWMZOA==

Sec-WebSocket-Version: 8

2013-03-18 17:03:51+0000 [Uninitialized] TX Octets to 192.168.13.50:8080 : sync = False, octets = 474554202f676174657761792f776562736f636b657463616c6c3f73657373696f6e49443d465747572d37373063636538312d333665352d343537362d626665362d33646234636133386264323120485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e352e31340d0a486f73743a203139322e3136382e31332e35303a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a2042736342444a2b473866424b5335533652574d5a4f413d3d0d0a5365632d576562536f636b65742d56657273696f6e3a20380d0a0d0a

2013-03-18 17:03:51+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d436f796f74652f312e310d0a5365742d436f6f6b69653a204a53455353494f4e49443d64432d45755237547670756d586670793679785546447a6f3b20506174683d2f676174657761790d0a4163636573732d436f6e74726f6c2d416c6c6f772d486561646572733a20636f6e74656e742d747970650d0a4163636573732d436f6e74726f6c2d416c6c6f772d43726564656e7469616c733a20747275650d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d4c6f636174696f6e3a2077733a2f2f3139322e3136382e31332e35303a383038302f676174657761792f776562736f636b657463616c6c0d0a5365632d576562536f636b65742d4163636570743a20644766445a6f6c736a665978416f43523665324d355a454e6347593d0d0a446174653a204d6f6e2c203138204d617220323031332031373a30333a353320474d540d0a0d0a

2013-03-18 17:03:51+0000 [RequestTestClient,client] received HTTP response:

HTTP/1.1 101 Switching Protocols

Server: Apache-Coyote/1.1

Set-Cookie: JSESSIONID=dC-EuR7TvpumXfpy6yxUFDzo; Path=/gateway

Access-Control-Allow-Headers: content-type

Access-Control-Allow-Credentials: true

Upgrade: WebSocket

Connection: Upgrade

Sec-WebSocket-Location: ws://192.168.13.50:8080/gateway/websocketcall

Sec-WebSocket-Accept: dGfDZolsjfYxAoCR6e2M5ZENcGY=

Date: Mon, 18 Mar 2013 17:03:53 GMT

2013-03-18 17:03:51+0000 [RequestTestClient,client] received HTTP status line in opening handshake : HTTP/1.1 101 Switching Protocols

2013-03-18 17:03:51+0000 [RequestTestClient,client] received HTTP headers in opening handshake : {‘upgrade’: u’WebSocket’, ‘sec-websocket-accept’: u’dGfDZolsjfYxAoCR6e2M5ZENcGY=’, ‘set-cookie’: u’JSESSIONID=dC-EuR7TvpumXfpy6yxUFDzo; Path=/gateway’, ‘server’: u’Apache-Coyote/1.1’, ‘connection’: u’Upgrade’, ‘access-control-allow-credentials’: u’true’, ‘date’: u’Mon, 18 Mar 2013 17:03:53 GMT’, ‘access-control-allow-headers’: u’content-type’, ‘sec-websocket-location’: u’ws://192.168.13.50:8080/gateway/websocketcall’}

2013-03-18 17:03:51+0000 [RequestTestClient,client] Connection opened

2013-03-18 17:03:51+0000 [RequestTestClient,client] Starting SWIFT initialisation…

2013-03-18 17:03:51+0000 [RequestTestClient,client] Sending INITIALISE message…

2013-03-18 17:03:51+0000 [RequestTestClient,client] TX Frame to 192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 0b5edf8f, length = 22, repeat_length = None, chopsize = None, sync = False, payload = {“type”: “INITIALISE”}

2013-03-18 17:03:51+0000 [RequestTestClient,client] TX Octets to 192.168.13.50:8080 : sync = False, octets = 81960b5edf8f707cabf67b3bfdb52b7c96c1420a96ce47178cca2923

2013-03-18 17:03:51+0000 [RequestTestClient,client] INITIALISE sent.

2013-03-18 17:03:51+0000 [RequestTestClient,client] RX Octets from 192.168.13.50:8080 : octets = 81a3971552ffcc6e708bee6537ddad371bb1de411bbedb5c01bec35c1db1c84607bcd45001acb5680f

2013-03-18 17:03:51+0000 [RequestTestClient,client] Protocol violation : masked server-to-client frame

2013-03-18 17:03:51+0000 [RequestTestClient,client] Failing connection : 1002 - masked server-to-client frame

2013-03-18 17:03:51+0000 [RequestTestClient,client] TX Frame to 192.168.13.50:8080 : fin = True, rsv = 0, opcode = 8, mask = b5b2035f, length = 31, repeat_length = None, chopsize = None, sync = False, payload = 03ea6d61736b6564207365727665722d746f2d636c69656e74206672616d65

2013-03-18 17:03:51+0000 [RequestTestClient,client] TX Octets to 192.168.13.50:8080 : sync = False, octets = 889fb5b2035fb6586e3ec6d9663b95c1662dc3d77172c1dd2e3cd9db6631c192652dd4df66

2013-03-18 17:03:51+0000 [RequestTestClient,client] RX Frame from 192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 971552ff, length = 35, payload =

2013-03-18 17:03:51+0000 [RequestTestClient,client] Connection lost: [Failure instance: Traceback (failure with no frames): <class ‘twisted.internet.error.ConnectionDone’>: Connection was closed cleanly.

2013-03-18 17:03:51+0000 [RequestTestClient,client] ]

2013-03-18 17:03:51+0000 [RequestTestClient,client] Stopping factory <autobahn.websocket.WebSocketClientFactory instance at 0x229d878>

2013-03-18 17:03:52+0000 [-] onCloseHandshakeTimeout fired

2013-03-18 17:03:52+0000 [-] dropping connection

2013-03-18 17:03:56+0000 [-] skipping onOpenHandshakeTimeout since WebSocket connection already closed

Kind regards,

Thom

On Monday, March 18, 2013 11:53:24 AM UTC, Tobias Oberstein wrote:

Thomas,

sorry (forgot), could you please set both

debug = True, debugCodePaths = True

WebSocketClientFactory and resend your log output?

I suspect there might be a protocol violation triggering the immediate
drop of connection when receiving the first WS message from server.

You can also control that behavior by setting

setProtocolOptions(failByDrop = False)

on your factory.

Tobias

Am 18.03.2013 08:31, schrieb Thomas Madhavan:

Hello,

Using twisted.python logger, the full log is shown below:

2013-03-18 07:29:12+0000 [-] Log opened.

2013-03-18 07:29:12+0000 [-]

ws://192.168.13.50:8080/gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7

2013-03-18 07:29:12+0000 [-] Starting factory

<autobahn.websocket.WebSocketClientFactory instance at 0x2888878>

2013-03-18 07:29:12+0000 [Uninitialized] connection to

192.168.13.50:8080 established

2013-03-18 07:29:12+0000 [Uninitialized] GET

/gateway/websocketcall?sessionID=218dd719-4269-4181-a35f-7358c10acba7

HTTP/1.1

User-Agent: AutobahnPython/0.5.14

Host: 192.168.13.50:8080

Upgrade: WebSocket

Connection: Upgrade

Pragma: no-cache

Cache-Control: no-cache

Sec-WebSocket-Key: 4Td1vPwY2/B4FkAk2iAEcg==

Sec-WebSocket-Version: 8

2013-03-18 07:29:12+0000 [Uninitialized] TX Octets to 192.168.13.50:8080

: sync = False, octets =

474554202f676174657761792f776562736f636b657463616c6c3f73657373696f6e49443d32313864643731392d343236392d343138312d613335662d37333538633130616362613720485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e352e31340d0a486f73743a203139322e3136382e31332e35303a383038300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a203454643176507759322f4234466b416b3269414563673d3d0d0a5365632d576562536f636b65742d56657273696f6e3a20380d0a0d0a

2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from

192.168.13.50:8080 : octets =

485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d436f796f74652f312e310d0a5365742d436f6f6b69653a204a53455353494f4e49443d3463654b4b6d55696e6e5263424475494c563571444836763b20506174683d2f676174657761790d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a5365632d576562536f636b65742d4c6f636174696f6e3a2077733a2f2f3139322e3136382e31332e35303a383038302f676174657761792f776562736f636b657463616c6c0d0a5365632d576562536f636b65742d4163636570743a20774e384a5853585166634646366643334e37575731664b754c78513d0d0a446174653a204d6f6e2c203138204d617220323031332030373a32393a313320474d540d0a0d0a

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP response:

HTTP/1.1 101 Switching Protocols

Server: Apache-Coyote/1.1

Set-Cookie: JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway

Upgrade: WebSocket

Connection: Upgrade

Sec-WebSocket-Location: ws://192.168.13.50:8080/gateway/websocketcall

Sec-WebSocket-Accept: wN8JXSXQfcFF6fC3N7WW1fKuLxQ=

Date: Mon, 18 Mar 2013 07:29:13 GMT

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP status

line in opening handshake : HTTP/1.1 101 Switching Protocols

2013-03-18 07:29:12+0000 [RequestTestClient,client] received HTTP

headers in opening handshake : {‘upgrade’: u’WebSocket’,

‘sec-websocket-accept’: u’wN8JXSXQfcFF6fC3N7WW1fKuLxQ=’, ‘set-cookie’:

u’JSESSIONID=4ceKKmUinnRcBDuILV5qDH6v; Path=/gateway’, ‘server’:

u’Apache-Coyote/1.1’, ‘connection’: u’Upgrade’,

‘sec-websocket-location’:

u’ws://192.168.13.50:8080/gateway/websocketcall’, ‘date’: u’Mon, 18 Mar

2013 07:29:13 GMT’}

2013-03-18 07:29:12+0000 [RequestTestClient,client] Connection opened

2013-03-18 07:29:12+0000 [RequestTestClient,client] Starting SWIFT

initialisation…

2013-03-18 07:29:12+0000 [RequestTestClient,client] Sending INITIALISE

message…

2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Frame to

192.168.13.50:8080 : fin = True, rsv = 0, opcode = 1, mask = 9382cbdc,

length = 22, repeat_length = None, chopsize = None, sync = False,

payload = {“type”: “INITIALISE”}

2013-03-18 07:29:12+0000 [RequestTestClient,client] TX Octets to

192.168.13.50:8080 : sync = False, octets =

81969382cbdce8a0bfa5e3e7e9e6b3a08292dad6829ddfcb9899b1ff

2013-03-18 07:29:12+0000 [RequestTestClient,client] INITIALISE sent.

2013-03-18 07:29:12+0000 [RequestTestClient,client] RX Octets from

192.168.13.50:8080 : octets =

81a1402f781c3b0d0c65304a5a266266365514663950097c394809603643137a3b5f057c2b3e3d

2013-03-18 07:29:12+0000 [-] Connection lost: [Failure instance:

Traceback (failure with no frames): <class

‘twisted.internet.error.ConnectionAborted’>:

2013-03-18 07:29:12+0000 [-] Connection was aborted locally, using

2013-03-18 07:29:12+0000 [-]

L{twisted.internet.interfaces.ITCPTransport.abortConnection}.

2013-03-18 07:29:12+0000 [-]

2013-03-18 07:29:12+0000 [-] @since: 11.1

2013-03-18 07:29:12+0000 [-] .

2013-03-18 07:29:12+0000 [-] ]

2013-03-18 07:29:12+0000 [-] Stopping factory

<autobahn.websocket.WebSocketClientFactory instance at 0x2888878>

The server being used is an in house Java application server, running on

JBoss AS 7. I’m not sure which Java WS library is being used, or if it

has been written from scratch.

Thom

On Saturday, March 16, 2013 9:40:14 AM UTC, Tobias Oberstein wrote:

Thomas,
could you attach the complete log from Autobahn (with debug = True ..as
you already do)?
What server are you using?
Tobias
Am 13.03.2013 12:44, schrieb Thomas Madhavan:
 > Hi all,
 >
 > I'm trying to set up a simple bit of communication between my
Python WS
 > client, and a server that is processing and responding to particular
 > Json requests.
 >
 > Using another Python websocket client, I send a Json request like
so:
 >
 > {'type' : 'INITIALISE'}
 >
 > and get a Json response:
 >
 > {'type' : 'INITIALISATION SUCCESS'}
 >
 > as expected. When I try to use Autobahn I get the following error as
 > soon as I try to call sendMessage():
 >
 > [Failure instance: Traceback (failure with no frames): <class
 > 'twisted.internet.error.ConnectionAborted'>:
 >      Connection was aborted locally, using
 >      L{twisted.internet.interfaces.ITCPTransport.abortConnection}.
 >
 >      @since: 11.1
 > .]
 >
 > My WS URI looks something like:
 > " ws://[ip:port]/gateway/websocketcall?sessionID=xxxxx "
 >
 > Code is below. Does anyone know why this may be happening?
Thanks. I'm
 > running on Python 2.7, Ubuntu 12.10 64-bit, Twisted 12.1.0.
 >
 > Many thanks
 >
 >
 > class RequestTestClient(WebSocketClientProtocol):
 >      def onMessage(self, message, binary):
 >          print "Received message: " + message
 >          #reactor.callLater(self.processMessage(message))
 > #@UndefinedVariable
 >      def connectionLost(self, reason):
 >          print "Connection lost: " + str(reason)
 >      def onClose(self):
 >          print "Closing connection"
 >      def onOpen(self):
 >          print "Connection opened"
 >          self.send_initialise()
 >      def send_initialise(self):
 >          msg = json.dumps({
 >                                'type':'INITIALISE',
 >                                })
 >
 >          print "Sending INITIALISE message..."
 >          self.sendMessage(msg)
 >          print "INITIALISE sent."
 >
 > def doLoginAndGetSessionInformation():
 >      [...]
 >
 > def decodeSessionIdAndGetWsUri(sessionId):
 >      [...]
 >
 > if __name__=='__main__':
 >      wsUri =
 >
decodeSessionIdAndGetWsUri(json.loads(doLoginAndGetSessionInformation())['sessionid'])
 >      print wsUri
 >      wsFactory = WebSocketClientFactory(url=wsUri, debug = True)
 >      wsFactory.protocol = RequestTestClient
 >
 >      connectWS(wsFactory)
 >      reactor.run() #@UndefinedVariable
 >
 > --
 > You received this message because you are subscribed to the Google
 > Groups "Autobahn" group.
 > To unsubscribe from this group and stop receiving emails from it,
send
 > an email to autobahnws+...@googlegroups.com <javascript:>.
 > For more options, visit [https://groups.google.com/groups/opt_out](https://groups.google.com/groups/opt_out)
<[https://groups.google.com/groups/opt_out](https://groups.google.com/groups/opt_out)>.
 >
 >

You received this message because you are subscribed to the Google

Groups “Autobahn” group.

To unsubscribe from this group and stop receiving emails from it, send

an email to autobahnws+...@googlegroups.com.

For more options, visit https://groups.google.com/groups/opt_out.

0 Likes

#6

The server does mask WebSocket frames sent to the client. This is illegal according to RFC6455. Only client-to-server masking is allowed (and mandatory).

However, you can make Autobahn accept that behavior anyway by setting the following option:

setProtocolOptions(acceptMaskedServerFrames = True)

on your WebSocketClientFactory.

Apart from that, you should really also fix your server .. best would be to run the complete AutobahnTestsuite for max. compat. etc.

Tobias

···

Am 18.03.2013 18:05, schrieb Thomas Madhavan:

2013-03-18 17:01:02+0000 [RequestTestClient,client] Protocol violation :
masked server-to-client frame
2013-03-18 17:01:02+0000 [RequestTestClient,client] Failing connection :
1002 - masked server-to-client frame

0 Likes

#7

With failByDrop = False, you can see that Autobahn performs a full closing handshake with the server, providing the specific reason ("1002 - masked server-to-client frame").

Hence, you should be able to see that in your server logs also .. if you log close codes/reasons.

Tobias

···

Am 18.03.2013 18:05, schrieb Thomas Madhavan:

2013-03-18 17:03:51+0000 [RequestTestClient,client] Failing connection :
1002 - masked server-to-client frame
2013-03-18 17:03:51+0000 [RequestTestClient,client] TX Frame to
192.168.13.50:8080 : fin = True, rsv = 0, opcode = 8, mask = b5b2035f,
length = 31, repeat_length = None, chopsize = None, sync = False,
payload = 03ea6d61736b6564207365727665722d746f2d636c69656e74206672616d65

0 Likes