Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Server Error: ERROR 2020-05-28 02:33:05,356 Uncaught exception in /client/ws/speech #237

Open
WorldHellow opened this issue May 27, 2020 · 0 comments

Comments

@WorldHellow
Copy link

WorldHellow commented May 27, 2020

I am exposing my local server through ngrok and ssh. I am using kaldi-gstreamer.

Worker output when I speak through the mic

2020-05-28 02:32:43 -    INFO:   __main__: Opened websocket connection to server
2020-05-28 02:32:53 -   DEBUG:   __main__: <undefined>: Got message from server of type <class 'ws4py.messaging.TextMessage'>
2020-05-28 02:32:53 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Initializing request
2020-05-28 02:32:53 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Setting caps to audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1
2020-05-28 02:32:53 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Connecting audio decoder
2020-05-28 02:32:53 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Connected audio decoder
2020-05-28 02:32:53 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Started timeout guard
2020-05-28 02:32:53 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:53 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Initialized request
2020-05-28 02:32:54 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:55 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:56 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:32:56 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 8916 to pipeline
2020-05-28 02:32:56 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:32:56 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:57 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:32:57 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 8916 to pipeline
2020-05-28 02:32:57 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:32:57 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:58 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:32:58 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 5944 to pipeline
2020-05-28 02:32:58 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:32:58 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:32:59 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:32:59 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 8916 to pipeline
2020-05-28 02:32:59 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:32:59 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:33:00 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:33:00 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:33:00 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 8918 to pipeline
2020-05-28 02:33:00 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:33:01 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:33:01 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 5944 to pipeline
2020-05-28 02:33:01 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:33:01 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:33:02 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:33:02 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer of size 5944 to pipeline
2020-05-28 02:33:02 -   DEBUG:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pushing buffer done
2020-05-28 02:33:02 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Checking that decoder hasn't been silent for more than 10 seconds
2020-05-28 02:33:03 - WARNING:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: More than 10 seconds from last decoder hypothesis update, cancelling
2020-05-28 02:33:03 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Master disconnected before decoder reached EOS?
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Sending EOS to pipeline in order to cancel processing
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Cancelled pipeline
2020-05-28 02:33:03 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Waiting for EOS from decoder
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got final result: ایک سو
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got full final result: {"status": 0, "result": {"final": true, "hypotheses": [{"transcript": "ایک سو", "likelihood": 19.0102}]}, "segment-length": 1.65, "segment-start": 0.0, "total-length": 1.65}
2020-05-28 02:33:03 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Before postprocessing: {u'status': 0, u'segment-start': 0.0, u'segment-length': 1.65, u'total-length': 1.65, u'result': {u'hypotheses': [{u'likelihood': 19.0102, u'transcript': u'ایک سو'}], u'final': True}, 'segment': 0, 'id': u'a7bc3e4d-d3cc-4732-8e91-492db73090c3'}
2020-05-28 02:33:03 -   DEBUG:       root: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Waiting for postprocessor lock
2020-05-28 02:33:03 -   DEBUG:       root: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Starting postprocessing: ایک سو
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Pipeline received eos signal
2020-05-28 02:33:03 -    INFO:   decoder2: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Resetting decoder state
2020-05-28 02:33:03 -   DEBUG:       root: Waiting until processing threads finish (1)
2020-05-28 02:33:04 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2020-05-28 02:33:04 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Ignoring data, worker already in state 8
2020-05-28 02:33:04 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Waiting for EOS from decoder
2020-05-28 02:33:04 -   DEBUG:       root: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Postprocessing returned: ایک سو.

2020-05-28 02:33:04 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Postprocessing done.
2020-05-28 02:33:04 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: After postprocessing: {u'status': 0, u'segment-start': 0.0, u'segment-length': 1.65, u'total-length': 1.65, u'result': {u'hypotheses': [{u'likelihood': 19.0102, u'transcript': u'ایک سو.', 'original-transcript': u'ایک سو'}], u'final': True}, 'segment': 0, 'id': u'a7bc3e4d-d3cc-4732-8e91-492db73090c3'}
2020-05-28 02:33:04 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Sending adaptation state to client...
2020-05-28 02:33:04 -   DEBUG:      ws4py: Closing message received (1000) ''
2020-05-28 02:33:04 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Websocket closed() called
2020-05-28 02:33:04 -   DEBUG:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Websocket closed() finished
2020-05-28 02:33:05 -    INFO:   decoder2: <undefined>: Resetting decoder state
2020-05-28 02:33:05 -    INFO:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Finished waiting for EOS
2020-05-28 02:33:05 - WARNING:   __main__: a7bc3e4d-d3cc-4732-8e91-492db73090c3: Failed to send error event to master
2020-05-28 02:33:05 -    INFO:   __main__: Opening websocket connection to master server
2020-05-28 02:33:05 -    INFO:   __main__: Opened websocket connection to server

Server output:

INFO 2020-05-28 02:32:42,855 28292b79-0c61-4949-a989-131533584eb8: Handling on_connection_close()
    INFO 2020-05-28 02:32:42,855 28292b79-0c61-4949-a989-131533584eb8: Closing worker connection
    INFO 2020-05-28 02:32:43,819 101 GET /worker/ws/speech (127.0.0.1) 0.89ms
    INFO 2020-05-28 02:32:43,819 New worker available <__main__.WorkerSocketHandler object at 0x7f3631a85b90>
    INFO 2020-05-28 02:32:53,749 101 GET /client/ws/speech?content-type=audio/x-raw,+layout=(string)interleaved,+rate=(int)16000,+format=(string)S16LE,+channels=(int)1&user-id=c376398a-ebe8-4f56-ae20-521b84c0aa30&content-id=90507e7f-fa0d-4e46-a437-406dea0c0177 (127.0.0.1) 1.24ms
    INFO 2020-05-28 02:32:53,749 a7bc3e4d-d3cc-4732-8e91-492db73090c3: OPEN
    INFO 2020-05-28 02:32:53,750 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Request arguments: user-id="c376398a-ebe8-4f56-ae20-521b84c0aa30" content-type="audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1" content-id="90507e7f-fa0d-4e46-a437-406dea0c0177"
    INFO 2020-05-28 02:32:53,750 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Using worker <__main__.DecoderSocketHandler object at 0x7f3631a941d0>
    INFO 2020-05-28 02:32:53,750 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Using content type: audio/x-raw, layout=(string)interleaved, rate=(int)16000, format=(string)S16LE, channels=(int)1
    INFO 2020-05-28 02:32:56,035 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8916 to worker
    INFO 2020-05-28 02:32:57,287 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8916 to worker
    INFO 2020-05-28 02:32:58,131 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 5944 to worker
    INFO 2020-05-28 02:32:59,607 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8916 to worker
    INFO 2020-05-28 02:33:00,855 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8918 to worker
    INFO 2020-05-28 02:33:01,688 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 5944 to worker
    INFO 2020-05-28 02:33:02,546 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 5944 to worker
    INFO 2020-05-28 02:33:04,024 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8916 to worker
    INFO 2020-05-28 02:33:04,846 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Sending event {u'status': 0, u'segment-start': 0.0, u'segment-length': 1.65, u'total-length': 1.65, u'result': ... to client
    INFO 2020-05-28 02:33:04,859 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Sending event {u'status': 0, u'adaptation_state': {u'type': u'string+gzip+base64', u'id': u'a7bc3e4d-d3cc-4732-... to client
    INFO 2020-05-28 02:33:04,860 Worker <__main__.WorkerSocketHandler object at 0x7f3631a85b90> leaving
    INFO 2020-05-28 02:33:05,356 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Forwarding client message (<type 'str'>) of length 8916 to worker
   ERROR 2020-05-28 02:33:05,356 Uncaught exception in /client/ws/speech
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/tornado/websocket.py", line 494, in _run_callback
    result = callback(*args, **kwargs)
  File "/home/saad/kaldi-gstreamer-server/kaldigstserver/master_server.py", line 319, in on_message
    self.worker.write_message(message, binary=True)
  File "/usr/local/lib/python2.7/dist-packages/tornado/websocket.py", line 249, in write_message
    raise WebSocketClosedError()
WebSocketClosedError
    INFO 2020-05-28 02:33:05,357 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Handling on_connection_close()
    INFO 2020-05-28 02:33:05,357 a7bc3e4d-d3cc-4732-8e91-492db73090c3: Closing worker connection
    INFO 2020-05-28 02:33:05,864 101 GET /worker/ws/speech (127.0.0.1) 1.00ms
    INFO 2020-05-28 02:33:05,865 New worker available <__main__.WorkerSocketHandler object at 0x7f3631a94390>
    INFO 2020-05-28 02:33:12,935 Status listener left
    INFO 2020-05-28 02:34:06,125 Status listener left 

Sometimes the output is generated properly and sometimes only one or two words are recognized.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant