It appears that a new connection is allowed in the time when client closes connection, but worker has not received EOS from decoder about kaldi-gstreamer-server HOT 13 OPEN

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

from kaldi-gstreamer-server.

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

from kaldi-gstreamer-server.

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 Lawouach/WebSocket-for-Python#121.

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

from kaldi-gstreamer-server.

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?

from kaldi-gstreamer-server.

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

from kaldi-gstreamer-server.

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.

from kaldi-gstreamer-server.

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
#7 (comment)
.

from kaldi-gstreamer-server.

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

from kaldi-gstreamer-server.

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: Lawouach/WebSocket-for-Python#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

from kaldi-gstreamer-server.

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.

from kaldi-gstreamer-server.

same case, still experiencing even with ws4py==0.3.2

from kaldi-gstreamer-server.

the problem is still there!

from kaldi-gstreamer-server.

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

from kaldi-gstreamer-server.