search

nodesign / weio

weio
http://we-io.net
128 stars 35 forks source link

Possible Race Condition on Server Push #217

Closed drasko closed 8 years ago

drasko commented 9 years ago

For some reason, examples that use serverPush() break after some time with the error message presented below.

This example: https://github.com/nodesign/weio/blob/master/examples/analog/analogReadPotentio_JS breaks.

So is this one: https://github.com/nodesign/weio/tree/master/examples/webApps/bgColorLEDWEB.

This makes usage of the board very unstable and should be treated in urgenence.

Log:

MESSAGE analogRead {'data': 765, 'pin': 25} [25] 32601802-01b7-459f-bd3b-6be518383511

Exception in thread Thread-1:

ERR 0 : Exception in thread Thread-1:

STDOUT PUSHING: fromAdc

PUSHING: fromAdc

Traceback (most recent call last):

ERR 0 : Traceback (most recent call last):

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner

ERR 1 : File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner

error in file : /usr/lib/python2.7/threading.py error in line : 810 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x111f600>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x111f600>

self.run()

ERR 2 : self.run()

STDOUT MESSAGE analogRead {'data': 776, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 776, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/threading.py", line 763, in run

ERR 3 : File "/usr/lib/python2.7/threading.py", line 763, in run

error in file : /usr/lib/python2.7/threading.py error in line : 763 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self.__target(*self.__args, **self.__kwargs)

ERR 4 : self.target(_self.__args, *_self.kwargs)

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "./weioRunner.py", line 344, in listenerThread

ERR 5 : File "./weioRunner.py", line 344, in listenerThread

error in file : ./weioRunner.py error in line : 344 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1118b38>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1118b38>

weioRunnerGlobals.weioConnections[connUuid].send(json.dumps(result))

ERR 6 : weioRunnerGlobals.weioConnections[connUuid].send(json.dumps(result))

STDOUT MESSAGE analogRead {'data': 763, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 763, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/site-packages/sockjs/tornado/conn.py", line 49, in send

ERR 7 : File "/usr/lib/python2.7/site-packages/sockjs/tornado/conn.py", line 49, in send

error in file : /usr/lib/python2.7/site-packages/sockjs/tornado/conn.py error in line : 49 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self.session.send_message(message, binary=binary)

ERR 8 : self.session.send_message(message, binary=binary)

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 324, in send_message

ERR 9 : File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 324, in send_message

error in file : /usr/lib/python2.7/site-packages/sockjs/tornado/session.py error in line : 324 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1119b68>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1119b68>

self.send_jsonified(proto.json_encode(bytes_to_str(msg)), stats)

ERR 10 : self.send_jsonified(proto.json_encode(bytes_to_str(msg)), stats)

STDOUT MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 345, in send_jsonified

ERR 11 : File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 345, in send_jsonified

error in file : /usr/lib/python2.7/site-packages/sockjs/tornado/session.py error in line : 345 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self.flush()

ERR 12 : self.flush()

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 365, in flush

ERR 13 : File "/usr/lib/python2.7/site-packages/sockjs/tornado/session.py", line 365, in flush

error in file : /usr/lib/python2.7/site-packages/sockjs/tornado/session.py error in line : 365 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1158878>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x1158878>

self.handler.send_pack('a[%s]' % self.send_queue)

ERR 14 : self.handler.send_pack('a[%s]' % self.send_queue)

STDOUT MESSAGE analogRead {'data': 763, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 763, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/site-packages/sockjs/tornado/transports/xhrstreaming.py", line 46, in send_pack

ERR 15 : File "/usr/lib/python2.7/site-packages/sockjs/tornado/transports/xhrstreaming.py", line 46, in send_pack

error in file : /usr/lib/python2.7/site-packages/sockjs/tornado/transports/xhrstreaming.py error in line : 46 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self.flush(callback=self.send_complete)

ERR 16 : self.flush(callback=self.send_complete)

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/site-packages/tornado/web.py", line 705, in flush

ERR 17 : File "/usr/lib/python2.7/site-packages/tornado/web.py", line 705, in flush

error in file : /usr/lib/python2.7/site-packages/tornado/web.py error in line : 705 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x111f600>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x111f600>

self.request.write(headers + chunk, callback=callback)

ERR 18 : self.request.write(headers + chunk, callback=callback)

STDOUT MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/site-packages/tornado/httpserver.py", line 470, in write

ERR 19 : File "/usr/lib/python2.7/site-packages/tornado/httpserver.py", line 470, in write

error in file : /usr/lib/python2.7/site-packages/tornado/httpserver.py error in line : 470 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self.connection.write(chunk, callback=callback)

ERR 20 : self.connection.write(chunk, callback=callback)

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/site-packages/tornado/httpserver.py", line 234, in write

ERR 21 : File "/usr/lib/python2.7/site-packages/tornado/httpserver.py", line 234, in write

error in file : /usr/lib/python2.7/site-packages/tornado/httpserver.py error in line : 234 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x110c010>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x110c010>

self.stream.write(chunk, self._on_write_complete)

ERR 22 : self.stream.write(chunk, self._on_write_complete)

STDOUT MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

MESSAGE analogRead {'data': 764, 'pin': 25} [25] 91200ecc-6b38-457c-97f0-54e384c9c455

File "/usr/lib/python2.7/site-packages/tornado/iostream.py", line 214, in write

ERR 23 : File "/usr/lib/python2.7/site-packages/tornado/iostream.py", line 214, in write

error in file : /usr/lib/python2.7/site-packages/tornado/iostream.py error in line : 214 STDOUT PUSHING: fromAdc

PUSHING: fromAdc

self._handle_write()

ERR 24 : self._handle_write()

STDOUT CALLBACK IS NONE!

CALLBACK IS NONE!

File "/usr/lib/python2.7/site-packages/tornado/iostream.py", line 505, in _handle_write

ERR 25 : File "/usr/lib/python2.7/site-packages/tornado/iostream.py", line 505, in _handle_write

error in file : /usr/lib/python2.7/site-packages/tornado/iostream.py error in line : 505 STDOUT GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x115a130>

GOT MSG: <weioLib.weioRunnerGlobals.userAgentMessage instance at 0x115a130>

num_bytes = self.write_to_fd(self._write_buffer[0])

ERR 26 : num_bytes = self.write_to_fd(self._write_buffer[0])

STDOUT MESSAGE analogRead {'data': 763, 'pin': 25} [25] 3233511b-d246-4454-8b92-5e7c5089c053

MESSAGE analogRead {'data': 763, 'pin': 25} [25] 3233511b-d246-4454-8b92-5e7c5089c053

IndexError: deque index out of range

ERR 27 : IndexError: deque index out of range

STDOUT PUSHING: fromAdc

PUSHING: fromAdc

ERR 28 :

drasko commented 9 years ago

After some thinking, I got a conclusion that listener_thread (https://github.com/nodesign/weio/blob/master/weioRunner.py#L320), that gets a messages from Python and pushes them to SockJS Websocket connections hits the exception at one point and dies.

After that server push will never work, as there is no running thread to accept messages from Python and send them back to JS frontend. All JS functions calls will be unanswered - they will still be accepted and executed on the board, but no result will be sent back to JS.

Currently the only way to restart listener_thread is restarting the sever itself, as it is started only once, on the weioRunner.py user Tornado start: https://github.com/nodesign/weio/blob/master/weioRunner.py#L464

drasko commented 9 years ago

Might be fixed by https://github.com/nodesign/weio/commit/415a3cc5f73d47a9cdce745a8c7ef9292365dcb2

Has to be tested!

ks156 commented 9 years ago

Intensively tested, and seems fixed.

ks156 commented 8 years ago

I never heard again about this problem. I'll close this issue.