kaldi-gstreamer-server icon indicating copy to clipboard operation
kaldi-gstreamer-server copied to clipboard

It appears that a new connection is allowed in the time when client closes connection, but worker has not received EOS from decoder

Open ngoel17 opened this issue 9 years ago • 13 comments

It appears that the worker is make available and a new connection from a client is allowed when a previous client session has closed connection, but the worker is still waiting for the Final results and EOS from the decoder.

This new connection will generally not lead to a good decode session. Worker should probably stay unavailable until it sends out the final results / adaptation state and then closes the connection.

ngoel17 avatar Nov 24 '14 13:11 ngoel17

I am not able to reproduce this. From what I see, everything is correct: when client disconnects, the worker waits until it's done decoding, and then reconnects to the server. It's very possible that I'm missing something though.

Can you perhaps post a worker and server log from the situation, or can you list steps how to reproduce this?

alumae avatar Nov 24 '14 15:11 alumae

Tanel, Here is a log. I think I know what the issue may be. I think the applet is forcefully disconnecting to start a new recording, and that messes up the server. (look at Master disconnected before decoder reached EOS). That part is probably not handled gracefully.

Nagendra

INFO 2014-11-24 12:25:06,318 a6e99a4e-f199-42af-9163-8608229771a6:

OPEN: user='none', content='none' INFO 2014-11-24 12:25:06,318 a6e99a4e-f199-42af-9163-8608229771a6: Using worker <main.DecoderSocketHandler object at 0xe5cbd0> INFO 2014-11-24 12:25:06,318 a6e99a4e-f199-42af-9163-8608229771a6: Using content type: audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1 2014-11-24 12:25:06 - DEBUG: main: : Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:06 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Initializing request 2014-11-24 12:25:06 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Setting caps to audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1 2014-11-24 12:25:06 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Connecting audio decoder 2014-11-24 12:25:06 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Connected audio decoder 2014-11-24 12:25:06 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Started timeout guard 2014-11-24 12:25:06 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Initialized request 2014-11-24 12:25:06 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Checking that decoder hasn't been silent for more than 30 seconds INFO 2014-11-24 12:25:06,370 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'unicode'>) of length 28616 to worker 2014-11-24 12:25:06 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:06 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Setting adaptation state to user-provided value INFO 2014-11-24 12:25:06,605 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 5944 to worker 2014-11-24 12:25:06 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:06 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 5944 to pipeline 2014-11-24 12:25:06 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done INFO 2014-11-24 12:25:06,838 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 8918 to worker 2014-11-24 12:25:06 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:06 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 8918 to pipeline 2014-11-24 12:25:06 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done INFO 2014-11-24 12:25:07,089 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:07 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done 2014-11-24 12:25:07 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Checking that decoder hasn't been silent for more than 30 seconds INFO 2014-11-24 12:25:07,336 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 5944 to worker 2014-11-24 12:25:07 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 5944 to pipeline 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done INFO 2014-11-24 12:25:07,622 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:07 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done INFO 2014-11-24 12:25:07,841 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:07 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:07 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done INFO 2014-11-24 12:25:08,090 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 5946 to worker 2014-11-24 12:25:08 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 5946 to pipeline 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done 2014-11-24 12:25:08 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Checking that decoder hasn't been silent for more than 30 seconds INFO 2014-11-24 12:25:08,340 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 5944 to worker 2014-11-24 12:25:08 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 5944 to pipeline 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done 2014-11-24 12:25:08 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Got partial result: 2014-11-24 12:25:08 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Postprocessing (final=False) result.. 2014-11-24 12:25:08 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Postprocessing done. INFO 2014-11-24 12:25:08,353 a6e99a4e-f199-42af-9163-8608229771a6: Sending event {u'status': 0, u'result': {u'hypotheses': [{u'transcript': u''}], u'final': False}} to client INFO 2014-11-24 12:25:08,566 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'str'>) of length 5944 to worker INFO 2014-11-24 12:25:08,566 a6e99a4e-f199-42af-9163-8608229771a6: Forwarding client message (<type 'unicode'>) of length 3 to worker 2014-11-24 12:25:08 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer of size 5944 to pipeline 2014-11-24 12:25:08 - DEBUG: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing buffer done 2014-11-24 12:25:08 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:08 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Pushing EOS to pipeline INFO 2014-11-24 12:25:09,307 a6e99a4e-f199-42af-9163-8608229771a6: Handling on_connection_close() INFO 2014-11-24 12:25:09,308 a6e99a4e-f199-42af-9163-8608229771a6: Closing worker connection 2014-11-24 12:25:09 - DEBUG: ws4py: Closing message received (1000) '' 2014-11-24 12:25:09 - DEBUG: main: a6e99a4e-f199-42af-9163-8608229771a6: Websocket closed() called 2014-11-24 12:25:09 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Master disconnected before decoder reached EOS? 2014-11-24 12:25:09 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Sending EOS to pipeline in order to cancel processing 2014-11-24 12:25:09 - INFO: decoder2: a6e99a4e-f199-42af-9163-8608229771a6: Cancelled pipeline 2014-11-24 12:25:09 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:09 - INFO: main: Opening websocket connection to master server INFO 2014-11-24 12:25:09,327 New worker available <main.WorkerSocketHandler object at 0xe5c610> 2014-11-24 12:25:09 - INFO: main: Opened websocket connection to server INFO 2014-11-24 12:25:09,347 4cd93095-7081-4847-a8b8-2ff9494991bc: OPEN: user='none', content='none' INFO 2014-11-24 12:25:09,347 4cd93095-7081-4847-a8b8-2ff9494991bc: Using worker <main.DecoderSocketHandler object at 0xe5ce50> INFO 2014-11-24 12:25:09,347 4cd93095-7081-4847-a8b8-2ff9494991bc: Using content type: audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1 2014-11-24 12:25:09 - DEBUG: main: : Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:09 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Initializing request 2014-11-24 12:25:09 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Setting caps to audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1 2014-11-24 12:25:09 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Started timeout guard 2014-11-24 12:25:09 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Checking that decoder hasn't been silent for more than 30 seconds 2014-11-24 12:25:09 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Initialized request INFO 2014-11-24 12:25:09,448 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'unicode'>) of length 28616 to worker 2014-11-24 12:25:09 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:09 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Setting adaptation state to user-provided value INFO 2014-11-24 12:25:09,661 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:09 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:09 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:09 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done INFO 2014-11-24 12:25:09,908 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:09 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:09 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:09 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done INFO 2014-11-24 12:25:10,159 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8918 to worker 2014-11-24 12:25:10 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8918 to pipeline 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done 2014-11-24 12:25:10 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:10 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Checking that decoder hasn't been silent for more than 30 seconds INFO 2014-11-24 12:25:10,410 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:10 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done INFO 2014-11-24 12:25:10,657 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 5944 to worker 2014-11-24 12:25:10 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 5944 to pipeline 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done INFO 2014-11-24 12:25:10,911 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:10 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:10 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done INFO 2014-11-24 12:25:11,160 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 8916 to worker 2014-11-24 12:25:11 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:11 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 8916 to pipeline 2014-11-24 12:25:11 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done 2014-11-24 12:25:11 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder INFO 2014-11-24 12:25:11,373 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'str'>) of length 2972 to worker INFO 2014-11-24 12:25:11,373 4cd93095-7081-4847-a8b8-2ff9494991bc: Forwarding client message (<type 'unicode'>) of length 3 to worker 2014-11-24 12:25:11 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2014-11-24 12:25:11 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer of size 2972 to pipeline 2014-11-24 12:25:11 - DEBUG: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing buffer done 2014-11-24 12:25:11 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got message from server of type <class 'ws4py.messaging.TextMessage'> 2014-11-24 12:25:11 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Pushing EOS to pipeline 2014-11-24 12:25:12 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder INFO 2014-11-24 12:25:12,395 4cd93095-7081-4847-a8b8-2ff9494991bc: Handling on_connection_close() INFO 2014-11-24 12:25:12,395 4cd93095-7081-4847-a8b8-2ff9494991bc: Closing worker connection 2014-11-24 12:25:12 - DEBUG: ws4py: Closing message received (1000) '' 2014-11-24 12:25:12 - DEBUG: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Websocket closed() called 2014-11-24 12:25:12 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Master disconnected before decoder reached EOS? 2014-11-24 12:25:12 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Sending EOS to pipeline in order to cancel processing 2014-11-24 12:25:12 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Cancelled pipeline 2014-11-24 12:25:12 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:12 - INFO: main: Opening websocket connection to master server INFO 2014-11-24 12:25:12,433 9f73bb31-7e83-4055-96f9-30b3963aa294: OPEN: user='none', content='none' WARNING 2014-11-24 12:25:12,434 9f73bb31-7e83-4055-96f9-30b3963aa294: No worker available for client request INFO 2014-11-24 12:25:12,434 9f73bb31-7e83-4055-96f9-30b3963aa294: Sending event {'status': 9, 'message': 'No decoder available, try again later'} to client INFO 2014-11-24 12:25:12,434 New worker available <main.WorkerSocketHandler object at 0xe5c8d0> 2014-11-24 12:25:12 - INFO: main: Opened websocket connection to server ERROR 2014-11-24 12:25:12,519 Uncaught exception in /client/ws/speech Traceback (most recent call last): File "/usr/lib64/python2.7/site-packages/tornado/websocket.py", line 369, in _run_callback callback(_args, *_kwargs) File "kaldigstserver/master_ssl_server.py", line 310, in on_message assert self.worker is not None AssertionError INFO 2014-11-24 12:25:12,520 9f73bb31-7e83-4055-96f9-30b3963aa294: Handling on_connection_close() 2014-11-24 12:25:13 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:13 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:14 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:14 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:15 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:15 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:16 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:16 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:17 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:17 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:18 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:18 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:19 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:19 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:20 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:20 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:21 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:21 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:22 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:22 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:23 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:23 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:24 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:24 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:25 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:25 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:26 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:26 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:27 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:27 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:28 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:28 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:29 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:29 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:30 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:30 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:31 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:31 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:32 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:32 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:33 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:33 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:34 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:34 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:35 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:35 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:36 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:36 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:37 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:37 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:38 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:38 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:39 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:39 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:40 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:40 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:41 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:41 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:42 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:42 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:43 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:43 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:44 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:44 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:45 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:45 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:46 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:46 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:47 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:47 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:48 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:48 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:49 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:49 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:50 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:50 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:51 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:51 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:52 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:52 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:53 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:53 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:54 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:54 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:55 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:55 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:56 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:56 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:57 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:57 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:58 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:58 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:25:59 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:25:59 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:00 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:00 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:01 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:01 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:02 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:02 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:03 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:03 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:04 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:04 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:05 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:05 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:06 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:06 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:07 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:07 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:08 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:08 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:09 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:09 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:10 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:10 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:11 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:11 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:12 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:12 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:13 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:13 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:14 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:14 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:15 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:15 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:16 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:16 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:17 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:17 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:18 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:18 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:19 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:19 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:20 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:20 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:21 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:21 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:22 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:22 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:23 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:23 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:24 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:24 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:25 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:25 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:26 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:26 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:27 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:27 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:28 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:28 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:29 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Giving up waiting after 81 tries 2014-11-24 12:26:29 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: Waiting for EOS from decoder 2014-11-24 12:26:29 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:30 - INFO: decoder2: 4cd93095-7081-4847-a8b8-2ff9494991bc: Got final result: the issue and they say 2014-11-24 12:26:30 - INFO: main: : Postprocessing (final=True) result.. 2014-11-24 12:26:30 - INFO: main: : Postprocessing done. ERROR 2014-11-24 12:26:30,409 Uncaught exception in /worker/ws/speech Traceback (most recent call last): File "/usr/lib64/python2.7/site-packages/tornado/websocket.py", line 369, in _run_callback callback(_args, *_kwargs) File "kaldigstserver/master_ssl_server.py", line 254, in on_message assert self.client_socket is not None AssertionError 2014-11-24 12:26:30 - DEBUG: main: : Websocket closed() called INFO 2014-11-24 12:26:30,410 Worker <main.WorkerSocketHandler object at 0xe5c8d0> leaving 2014-11-24 12:26:30 - INFO: main: a6e99a4e-f199-42af-9163-8608229771a6: EOS received, we can close now 2014-11-24 12:26:30 - INFO: main: Opening websocket connection to master server INFO 2014-11-24 12:26:30,443 New worker available <main.WorkerSocketHandler object at 0xe7e610> 2014-11-24 12:26:30 - INFO: main: Opened websocket connection to server 2014-11-24 12:26:30 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:31 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:32 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Giving up waiting after 81 tries 2014-11-24 12:26:32 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: Waiting for EOS from decoder 2014-11-24 12:26:33 - INFO: main: 4cd93095-7081-4847-a8b8-2ff9494991bc: EOS received, we can close now

On Mon, Nov 24, 2014 at 10:49 AM, Tanel Alumäe [email protected] wrote:

I am not able to reproduce this. From what I see, everything is correct: when client disconnects, the worker waits until it's done decoding, and then reconnects to the server. It's very possible that I'm missing something though.

Can you perhaps post a worker and server log from the situation, or can you list steps how to reproduce this?

— Reply to this email directly or view it on GitHub https://github.com/alumae/kaldi-gstreamer-server/issues/7#issuecomment-64213200 .

ngoel17 avatar Nov 24 '14 17:11 ngoel17

Are you using the latest code from trunk, and have you made any changes? I'm asking this because it seems that you have changed the counter to 80 (because you have lines like "Giving up waiting after 81 tries" in the log), so I was wondering if there are any other changes.

alumae avatar Nov 24 '14 19:11 alumae

That's the only change.. Well there is one more change to allow SSL connection by providing the SSL key.

On Mon, Nov 24, 2014 at 2:47 PM, Tanel Alumäe [email protected] wrote:

Are you using the latest code from trunk, and have you made any changes? I'm asking this because it seems that you have changed the counter to 80 (because you have lines like "Giving up waiting after 81 tries" in the log), so I was wondering if there are any other changes.

— Reply to this email directly or view it on GitHub https://github.com/alumae/kaldi-gstreamer-server/issues/7#issuecomment-64252108 .

ngoel17 avatar Nov 25 '14 00:11 ngoel17

I was able to finally reproduce this after upgrading my ws4py package, working on the fix now.

alumae avatar Nov 25 '14 11:11 alumae

This is caused by what I claim is a bug in ws4py 3.5.0. The problem is that ws4py finishes the websocket handling thread before the websocket has actually done its cleanup. I reported it here: https://github.com/Lawouach/WebSocket-for-Python/issues/152

The current workaround is to use an earlier version of ws4py (3.0.0 ... 3.2.0 should be fine). Install it like that using pip:

pip install ws4py==0.3.2

alumae avatar Nov 25 '14 15:11 alumae

I'm currently having what may be a related issue where, when I curl a bunch of files with a python script, the end of the output for one file sometimes ends up at the beginning of the next file. I tried forking a version of ws4py and making the fix suggested by @alumae in the WebSocket issue you linked to, but I'm still having the same problem. Also using time.sleep(60) between curls.

meitals avatar Dec 06 '16 22:12 meitals

hi all, I already install ws4py==0.3.2, but still got this issue, anyone can resolve this?thanks

2018-08-28 15:42:58 - INFO: decoder2: 5cb34134-8ab7-4c06-a89d-482b812fe057: Pipeline received eos signal 2018-08-28 15:42:58 - INFO: decoder2: 5cb34134-8ab7-4c06-a89d-482b812fe057: Resetting decoder state 2018-08-28 15:42:59 - DEBUG: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Checking that decoder hasn't been silent for more than 20 seconds 2018-08-28 15:43:00 - DEBUG: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Checking that decoder hasn't been silent for more than 20 seconds 2018-08-28 15:43:00 - DEBUG: ws4py: Closing message received (1000) '' 2018-08-28 15:43:00 - DEBUG: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Websocket closed() called 2018-08-28 15:43:00 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Master disconnected before decoder reached EOS? 2018-08-28 15:43:00 - INFO: decoder2: : Sending EOS to pipeline in order to cancel processing 2018-08-28 15:43:00 - INFO: decoder2: : Cancelled pipeline 2018-08-28 15:43:00 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:01 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:02 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:03 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:04 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:05 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:06 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:07 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:08 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:09 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:10 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:11 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:12 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:13 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:14 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:15 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:16 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:17 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:18 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:19 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:20 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:21 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:22 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:23 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:24 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:25 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:26 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:27 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:28 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:29 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Waiting for EOS from decoder 2018-08-28 15:43:30 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Giving up waiting after 31 tries 2018-08-28 15:43:30 - INFO: decoder2: : Resetting decoder state 2018-08-28 15:43:30 - INFO: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Finished waiting for EOS 2018-08-28 15:43:30 - DEBUG: main: 5cb34134-8ab7-4c06-a89d-482b812fe057: Websocket closed() finished 2018-08-28 15:43:31 - INFO: main: Opening websocket connection to master server 2018-08-28 15:43:31 - INFO: main: Opened websocket connection to server

DayanJ avatar Aug 28 '18 09:08 DayanJ

@alumae any help here ? Same issue as above even after using ws4py 0.3.2.

ghost avatar Oct 18 '18 12:10 ghost

same case, still experiencing even with ws4py==0.3.2

feddyfedfed avatar Oct 24 '18 00:10 feddyfedfed

the problem is still there!

manuelgentile avatar Nov 16 '18 17:11 manuelgentile

I faced a problem similar to this one.

I have implemented my own MyClient class of python3 version, and realized that the client dies due to bytes of messages delivered from the master server. This means that the client dies although the worker is still working, thereby the master server receives 0-length payload so it sends 'Closing message' immediately.

To alleviate this problem, I used 'ws4py 0.3.2' for the master and worker, and took ws4py 0.3.3 for my client. Now I see the problem is addressed, but again encounter 'warning code' of 1006 (reason: Going away) Anyhow the client works fine though.

This is related to the issue of https://github.com/Lawouach/WebSocket-for-Python/issues/121.

I hope this will help someone who is trying to make a client using python3.

bytecell avatar Feb 22 '19 19:02 bytecell

@bytecell do you use python3 or python2 for master and worker?

naxingyu avatar Oct 21 '19 09:10 naxingyu

Any update? the problem is still there!

teinhonglo avatar Feb 11 '22 01:02 teinhonglo