search

alumae / kaldi-gstreamer-server

Real-time full-duplex speech recognition server, based on the Kaldi toolkit and the GStreamer framwork.
BSD 2-Clause "Simplified" License
1.07k stars 341 forks source link

gstreamer server worker dies after sending response #81

Closed rudmonster closed 7 years ago

rudmonster commented 7 years ago

Hi... Thanks in advance for any help here. I am stuck with worker processes dying after the first request . The request gets completed and then the worker dies.

  1. I am using my own install of Kaldi .
  2. No errors on the master server.

3 Here are the logs from the worker : python kaldigstserver/worker.py -u ws://localhost:8888/worker/ws/speech -c sample_english_nnet2.yaml DEBUG 2017-06-08 00:47:05,383 Starting up worker 2017-06-08 00:47:05 - INFO: decoder2: Creating decoder using conf: {'logging': {'version': 1, 'root': {'level': 'DEBUG', 'handlers': ['console']}, 'formatters': {'simpleFormater': {'datefmt': '%Y-%m-%d %H:%M:%S', 'format': '%(asctime)s - %(levelname)7s: %(name)10s: %(message)s'}}, 'disable_existing_loggers': False, 'handlers': {'console': {'formatter': 'simpleFormater', 'class': 'logging.StreamHandler', 'level': 'DEBUG'}}}, 'use-vad': False, 'decoder': {'ivector-extraction-config': 'test/models/english/tedlium_nnet_ms_sp_online/conf/ivector_extractor.conf', 'num-nbest': 3, 'lattice-beam': 6.0, 'acoustic-scale': 0.083, 'do-endpointing': True, 'beam': 10.0, 'max-active': 10000, 'fst': 'test/models/english/tedlium_nnet_ms_sp_online/HCLG.fst', 'mfcc-config': 'test/models/english/tedlium_nnet_ms_sp_online/conf/mfcc.conf', 'use-threaded-decoder': True, 'traceback-period-in-secs': 0.25, 'model': 'test/models/english/tedlium_nnet_ms_sp_online/final.mdl', 'word-syms': 'test/models/english/tedlium_nnet_ms_sp_online/words.txt', 'endpoint-silence-phones': '1:2:3:4:5:6:7:8:9:10', 'chunk-length-in-secs': 0.25}, 'silence-timeout': 30, 'out-dir': 'tmp', 'use-nnet2': True} 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: ivector-extraction-config = test/models/english/tedlium_nnet_ms_sp_online/conf/ivector_extractor.conf 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: num-nbest = 3 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: lattice-beam = 6.0 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: acoustic-scale = 0.083 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: do-endpointing = True 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: beam = 10.0 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: max-active = 10000 2017-06-08 00:47:05 - INFO: decoder2: Setting decoder property: fst = test/models/english/tedlium_nnet_ms_sp_online/HCLG.fst 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: mfcc-config = test/models/english/tedlium_nnet_ms_sp_online/conf/mfcc.conf 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: traceback-period-in-secs = 0.25 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: model = test/models/english/tedlium_nnet_ms_sp_online/final.mdl 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: word-syms = test/models/english/tedlium_nnet_ms_sp_online/words.txt 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: endpoint-silence-phones = 1:2:3:4:5:6:7:8:9:10 2017-06-08 00:47:17 - INFO: decoder2: Setting decoder property: chunk-length-in-secs = 0.25 2017-06-08 00:47:17 - INFO: decoder2: Created GStreamer elements 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstAppSrc object at 0x7f61027f0c30 (GstAppSrc at 0x2c74db0)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstDecodeBin object at 0x7f61027f0910 (GstDecodeBin at 0x2c840e0)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstAudioConvert object at 0x7f61027f0a00 (GstAudioConvert at 0x2ca0d90)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstAudioResample object at 0x7f61027f0b40 (GstAudioResample at 0x2cae270)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstTee object at 0x7f61027f0b90 (GstTee at 0x2cb2000)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstQueue object at 0x7f61027f0dc0 (GstQueue at 0x2cb60c0)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstFileSink object at 0x7f61027f0e10 (GstFileSink at 0x2cbba10)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstQueue object at 0x7f61027f0e60 (GstQueue at 0x2cb63b0)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.Gstkaldinnet2onlinedecoder object at 0x7f61027f0eb0 (Gstkaldinnet2onlinedecoder at 0x2c9c400)> to the pipeline 2017-06-08 00:47:17 - DEBUG: decoder2: Adding <__gi__.GstFakeSink object at 0x7f61027f0f00 (GstFakeSink at 0x2d73610)> to the pipeline 2017-06-08 00:47:17 - INFO: decoder2: Linking GStreamer elements LOG ([5.2.11~1-6fe14]:ComputeDerivedVars():ivector-extractor.cc:183) Computing derived variables for iVector extractor LOG ([5.2.11~1-6fe14]:ComputeDerivedVars():ivector-extractor.cc:204) Done. 2017-06-08 00:47:17 - INFO: decoder2: Setting pipeline to READY 2017-06-08 00:47:17 - INFO: decoder2: Set pipeline to READY 2017-06-08 00:47:17 - INFO: __main__: Opening websocket connection to master server 2017-06-08 00:47:17 - INFO: __main__: Opened websocket connection to server 2017-06-08 00:48:24 - DEBUG: __main__: <undefined>: Got message from server of type <class 'ws4py.messaging.TextMessage'> 2017-06-08 00:48:24 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Initializing request 2017-06-08 00:48:24 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Started timeout guard 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Checking that decoder hasn't been silent for more than 30 seconds 2017-06-08 00:48:24 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Initialized request 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer of size 16384 to pipeline 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer done 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer of size 65536 to pipeline 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer done 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer of size 65536 to pipeline 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer done 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer of size 49196 to pipeline 2017-06-08 00:48:24 - DEBUG: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing buffer done 2017-06-08 00:48:24 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got message from server of type <class 'ws4py.messaging.BinaryMessage'> 2017-06-08 00:48:24 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Pushing EOS to pipeline 2017-06-08 00:48:24 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Connecting audio decoder 2017-06-08 00:48:24 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Connected audio decoder 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three 2017-06-08 00:48:25 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Checking that decoder hasn't been silent for more than 30 seconds 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:25 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:25 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six seven 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six seven eight 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six seven eight 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six seven eight to 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing (final=False) result.. 2017-06-08 00:48:26 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:26 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got partial result: one two three four five six seven eight to 2017-06-08 00:48:26 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Checking that decoder hasn't been silent for more than 30 seconds 2017-06-08 00:48:27 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got final result: one two three four five six seven eight 2017-06-08 00:48:27 - INFO: decoder2: 403de3b8-d20c-4400-abb1-f90e1682ee06: Got full final result: {"total-length": 6.12, "status": 0, "result": {"final": true, "hypotheses": [{"transcript": "one two three four five six seven eight", "likelihood": 153.665}, {"transcript": "one two three four five six seven eight and", "likelihood": 152.151}, {"transcript": "one two three four five six seven eight it", "likelihood": 152.047}]}, "segment-start": 0.0, "segment-length": 6.12} 2017-06-08 00:48:27 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Before postprocessing: {u'status': 0, u'segment-start': 0.0, u'segment-length': 6.12, u'total-length': 6.12, u'result': {u'hypotheses': [{u'likelihood': 153.665, u'transcript': u'one two three four five six seven eight'}, {u'likelihood': 152.151, u'transcript': u'one two three four five six seven eight and'}, {u'likelihood': 152.047, u'transcript': u'one two three four five six seven eight it'}], u'final': True}, 'segment': 0} 2017-06-08 00:48:27 - INFO: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: Postprocessing done. 2017-06-08 00:48:27 - DEBUG: __main__: 403de3b8-d20c-4400-abb1-f90e1682ee06: After postprocessing: {u'status': 0, u'segment-start': 0.0, u'segment-length': 6.12, u'total-length': 6.12, u'result': {u'hypotheses': [{u'likelihood': 153.665, u'transcript': u'one two three four five six seven eight'}, {u'likelihood': 152.151, u'transcript': u'one two three four five six seven eight and'}, {u'likelihood': 152.047, u'transcript': u'one two three four five six seven eight it'}], u'final': True}, 'segment': 0} terminate called after throwing an instance of 'std::system_error' what(): Invalid argument Aborted (core dumped)

  1. Here is the output I get from the client: curl -T test/data/english_test.wav "http://localhost:8888/client/dynamic/recognize" {"status": 0, "hypotheses": [{"utterance": "one two three four five six seven eight"}], "id": "403de3b8-d20c-4400-abb1-f90e1682ee06"}

5 Or from the python client : python kaldigstserver/client.py -r 32000 test/data/english_test.wav one two three four five six seven eight to Audio sent, now sending EOS one two three four five six seven eight one two three four five six seven eight Any help would be much appreciated!

PS. I am have cuda installed and am trying to make sure I use that for anything I can , but I have not seen a lot on gstreamer kaldi configuration concerning gstreamer-server.

Thanks again ,

rudmonster

alumae commented 7 years ago

The part that is interesting is terminate called after throwing an instance of 'std::system_error' what(): Invalid argument Aborted (core dumped). I am not sure, but maybe your Kaldi GStreamer plugin is compiled later than Kaldi istelf? Try to first recompile Kaldi (clean, compile) and then the GStreamer plugin.

lightslife commented 7 years ago

Maybe because of the pthread. Setting "use-threaded-decode: false" seems to be helpful.

alumae commented 7 years ago

It was caused by a bug in Kaldi, which is fixed now: https://github.com/kaldi-asr/kaldi/pull/1725