search

jcsilva / docker-kaldi-gstreamer-server

Dockerfile for kaldi-gstreamer-server.
BSD 2-Clause "Simplified" License
288 stars 139 forks source link

Test client gets stuck on "Audio sent, now sending EOS" when following the README's "practical example" #59

Closed craklyn closed 5 years ago

craklyn commented 5 years ago

Hi,

I'm trying to follow the README instructions to get running a basic "hello world". In particular, I've followed the "Practical Example" at the bottom of the README file.

In broad strokes, I start the server running with the following commands:

# Start docker
docker run -it -p 8080:80 -v /media/kaldi_models:/opt/models jcsilva/docker-kaldi-gstreamer-server:latest /bin/bash

# Within docker container, start master/worker services
/opt/start.sh -y /opt/models/sample_english_nnet2.yaml

Within a second terminal, I then run the websocket client:

python /tmp/client.py -u ws://localhost:8080/client/ws/speech -r 32000 /tmp/1272-128104-0000.wav

Within a couple seconds of sending the command, the second terminal responds to screen Audio sent, now sending EOS but after this nothing happens and the terminal becomes completely unresponsive, even to ctrl+c.

It looks like transcription is taking place, but the script running client.py never sees the results. Below is the full dump of worker.log. Thanks in advance for any help you can provide!

libudev: udev_has_devtmpfs: name_to_handle_at on /dev: Operation not permitted
libdc1394 error: Failed to initialize libdc1394
   DEBUG 2019-03-04 22:08:34,751 Starting up worker 
2019-03-04 22:08:34 -    INFO:   decoder2: Creating decoder using conf: {'post-processor': "perl -npe 'BEGIN {use IO::Handle; STDOUT->autoflush(1);} s/(.*)/\\1./;'", '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': '/opt/models/english/tedlium_nnet_ms_sp_online/conf/ivector_extractor.conf', 'num-nbest': 10, 'lattice-beam': 6.0, 'acoustic-scale': 0.083, 'do-endpointing': True, 'beam': 10.0, 'max-active': 10000, 'fst': '/opt/models/english/tedlium_nnet_ms_sp_online/HCLG.fst', 'mfcc-config': '/opt/models/english/tedlium_nnet_ms_sp_online/conf/mfcc.conf', 'use-threaded-decoder': True, 'traceback-period-in-secs': 0.25, 'model': '/opt/models/english/tedlium_nnet_ms_sp_online/final.mdl', 'word-syms': '/opt/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': 10, 'out-dir': 'tmp', 'use-nnet2': True}
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: ivector-extraction-config = /opt/models/english/tedlium_nnet_ms_sp_online/conf/ivector_extractor.conf
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: num-nbest = 10
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: lattice-beam = 6.0
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: acoustic-scale = 0.083
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: do-endpointing = True
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: beam = 10.0
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: max-active = 10000
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: mfcc-config = /opt/models/english/tedlium_nnet_ms_sp_online/conf/mfcc.conf
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: traceback-period-in-secs = 0.25
2019-03-04 22:08:34 -    INFO:   decoder2: Setting decoder property: word-syms = /opt/models/english/tedlium_nnet_ms_sp_online/words.txt
2019-03-04 22:08:35 -    INFO:   decoder2: Setting decoder property: endpoint-silence-phones = 1:2:3:4:5:6:7:8:9:10
2019-03-04 22:08:35 -    INFO:   decoder2: Setting decoder property: chunk-length-in-secs = 0.25
2019-03-04 22:08:35 -    INFO:   decoder2: Setting decoder property: fst = /opt/models/english/tedlium_nnet_ms_sp_online/HCLG.fst
2019-03-04 22:08:42 -    INFO:   decoder2: Setting decoder property: model = /opt/models/english/tedlium_nnet_ms_sp_online/final.mdl
2019-03-04 22:08:42 -    INFO:   decoder2: Created GStreamer elements
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstAppSrc object at 0x7f43dbea1370 (GstAppSrc at 0x2678bb0)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstDecodeBin object at 0x7f43dbea1320 (GstDecodeBin at 0x26d0060)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstAudioConvert object at 0x7f43dbea1410 (GstAudioConvert at 0x26d98f0)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstAudioResample object at 0x7f43dbea12d0 (GstAudioResample at 0x24c8f70)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstTee object at 0x7f43dbea13c0 (GstTee at 0x26e7000)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstQueue object at 0x7f43dbea14b0 (GstQueue at 0x26ea170)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstFileSink object at 0x7f43dbea1500 (GstFileSink at 0x26ee400)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstQueue object at 0x7f43dbea1550 (GstQueue at 0x26ea460)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.Gstkaldinnet2onlinedecoder object at 0x7f43dbea15a0 (Gstkaldinnet2onlinedecoder at 0x2708150)> to the pipeline
2019-03-04 22:08:42 -   DEBUG:   decoder2: Adding <__main__.GstFakeSink object at 0x7f43dbea15f0 (GstFakeSink at 0x2706210)> to the pipeline
2019-03-04 22:08:42 -    INFO:   decoder2: Linking GStreamer elements
LOG ([5.4.176~1-be967]:ComputeDerivedVars():ivector-extractor.cc:183) Computing derived variables for iVector extractor
LOG ([5.4.176~1-be967]:ComputeDerivedVars():ivector-extractor.cc:204) Done.
2019-03-04 22:08:43 -    INFO:   decoder2: Setting pipeline to READY
2019-03-04 22:08:43 -    INFO:   decoder2: Set pipeline to READY
2019-03-04 22:08:43 -    INFO:   __main__: Opening websocket connection to master server
2019-03-04 22:08:43 -    INFO:   __main__: Opened websocket connection to server
2019-03-04 22:09:09 -   DEBUG:   __main__: <undefined>: Got message from server of type <class 'ws4py.messaging.TextMessage'>
2019-03-04 22:09:09 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Initializing request
2019-03-04 22:09:09 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Started timeout guard
2019-03-04 22:09:09 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Initialized request
2019-03-04 22:09:09 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:09 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:09 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Connecting audio decoder
2019-03-04 22:09:09 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Connected audio decoder
2019-03-04 22:09:09 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:09 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:09 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:09 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:10 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:10 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:10 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: this
2019-03-04 22:09:10 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:10 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Starting postprocessing: this
2019-03-04 22:09:10 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:10 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: this to
2019-03-04 22:09:10 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:10 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:10 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:10 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:10 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: this to
2019-03-04 22:09:11 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:11 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr
2019-03-04 22:09:11 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:11 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:11 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:11 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:11 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the
2019-03-04 22:09:11 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:11 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:11 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:11 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the
2019-03-04 22:09:11 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:11 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:11 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle
2019-03-04 22:09:11 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:11 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:12 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:12 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the
2019-03-04 22:09:12 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:12 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:12 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:12 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:12 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle
2019-03-04 22:09:12 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:12 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:12 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:12 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle
2019-03-04 22:09:12 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:12 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:12 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes
2019-03-04 22:09:12 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:12 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:13 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:13 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and
2019-03-04 22:09:13 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:13 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:13 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:13 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:13 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we
2019-03-04 22:09:13 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:13 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:13 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:13 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad
2019-03-04 22:09:13 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:13 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:13 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:13 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:14 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:14 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to
2019-03-04 22:09:14 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:14 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:14 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:14 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:14 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to have
2019-03-04 22:09:14 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:14 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:14 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to welcome
2019-03-04 22:09:14 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:14 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:14 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:14 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to welcome
2019-03-04 22:09:14 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 8000 to pipeline
2019-03-04 22:09:14 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:14 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to welcome his
2019-03-04 22:09:14 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:14 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:15 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.BinaryMessage'>
2019-03-04 22:09:15 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer of size 3404 to pipeline
2019-03-04 22:09:15 -   DEBUG:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing buffer done
2019-03-04 22:09:15 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Got message from server of type <class 'ws4py.messaging.TextMessage'>
2019-03-04 22:09:15 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Pushing EOS to pipeline
2019-03-04 22:09:15 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:15 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got partial result: mr coulter is the apostle of the middle classes and we're glad to welcome his gospel
2019-03-04 22:09:15 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Postprocessing (final=False) result..
2019-03-04 22:09:15 -   DEBUG:       root: df0c7160-caf6-4343-b63a-2e5273371f50: Skipping postprocessing since post-processor already in use
2019-03-04 22:09:15 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got final result: mr coulter is the apostle of the middle classes and we're glad to welcome his gospel
2019-03-04 22:09:15 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Got full final result: {"status": 0, "result": {"final": true, "hypotheses": [{"transcript": "mr coulter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 162.891}, {"transcript": "mr coulter is the apostle of the middle classes and we are glad to welcome his gospel", "likelihood": 161.423}, {"transcript": "this to coulter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 159.477}, {"transcript": "but mr coulter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 159.301}, {"transcript": "mr coulter is the apostle have the middle classes and we're glad to welcome his gospel", "likelihood": 159.132}, {"transcript": "this to clutter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 158.691}, {"transcript": "mr coulter is the apostle of middle classes and we're glad to welcome his gospel", "likelihood": 158.547}, {"transcript": "mr coulter his the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 158.187}, {"transcript": "and mr coulter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 158.155}, {"transcript": "mr quarter is the apostle of the middle classes and we're glad to welcome his gospel", "likelihood": 158.083}]}, "segment-length": 5.84, "segment-start": 0.0, "total-length": 5.84}
2019-03-04 22:09:15 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Before postprocessing: {u'status': 0, u'segment-start': 0.0, u'segment-length': 5.84, u'total-length': 5.84, u'result': {u'hypotheses': [{u'likelihood': 162.891, u'transcript': u"mr coulter is the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 161.423, u'transcript': u'mr coulter is the apostle of the middle classes and we are glad to welcome his gospel'}, {u'likelihood': 159.477, u'transcript': u"this to coulter is the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 159.301, u'transcript': u"but mr coulter is the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 159.132, u'transcript': u"mr coulter is the apostle have the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 158.691, u'transcript': u"this to clutter is the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 158.547, u'transcript': u"mr coulter is the apostle of middle classes and we're glad to welcome his gospel"}, {u'likelihood': 158.187, u'transcript': u"mr coulter his the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 158.155, u'transcript': u"and mr coulter is the apostle of the middle classes and we're glad to welcome his gospel"}, {u'likelihood': 158.083, u'transcript': u"mr quarter is the apostle of the middle classes and we're glad to welcome his gospel"}], u'final': True}, 'segment': 0, 'id': u'df0c7160-caf6-4343-b63a-2e5273371f50'}
2019-03-04 22:09:16 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:17 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:18 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:19 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:20 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:21 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:22 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:23 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:24 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:25 -   DEBUG:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Checking that decoder hasn't been silent for more than 10 seconds
2019-03-04 22:09:26 - WARNING:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: More than 10 seconds from last decoder hypothesis update, cancelling
2019-03-04 22:09:26 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Master disconnected before decoder reached EOS?
2019-03-04 22:09:26 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Sending EOS to pipeline in order to cancel processing
2019-03-04 22:09:26 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Cancelled pipeline
2019-03-04 22:09:26 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:27 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:28 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:29 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:30 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:31 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:32 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:33 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:34 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:35 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:36 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:37 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:38 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:39 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:40 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:41 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:42 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:43 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:44 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:45 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:46 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:47 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:48 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:49 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:50 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:51 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:52 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:53 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:54 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:55 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Waiting for EOS from decoder
2019-03-04 22:09:56 -    INFO:   __main__: df0c7160-caf6-4343-b63a-2e5273371f50: Giving up waiting after 31 tries
2019-03-04 22:09:56 -    INFO:   decoder2: df0c7160-caf6-4343-b63a-2e5273371f50: Resetting decoder state
craklyn commented 5 years ago

To provide another datapoint, I've tried following along in this thread. I ran the suggested docker image by following the recipe docker run -p 9999:80 jcsilva:docker-kaldi-gstreamer-server:tedlium and the same script ran without problem. It seems that there's some difference between this image and the "current" image that's causing problems for me, but I'm not sure what's going on.

Any help is still appreciated. =] Thanks!

craklyn commented 5 years ago

I think I understand what was causing my problems.

The default docker version uses the python2 library tornado==5.0.2. When this library is installed, the websocket and HTTP API don't work for me.

I've found that by installing tornado==4.3, the "Practical Example" works great. Installing is, of course, as simple as typing pip install tornado==4.3 before running the start.sh script. I do get some compilation warnings and failures when doing this, but it's good enough to get the example working.

I'll include the compilation messages below for completeness. However, I think this comment can be marked as closed. Up to the maintainers whether to make any changes to the repo. =]

root@20acfc829e7a:/opt# pip install tornado==4.3
Downloading/unpacking tornado==4.3
  Downloading tornado-4.3.tar.gz (450kB): 450kB downloaded
  Running setup.py (path:/tmp/pip-build-zLo_HN/tornado/setup.py) egg_info for package tornado

    no previously-included directories found matching 'docs/build'
    warning: no files found matching 'tornado/test/README'
Downloading/unpacking backports.ssl-match-hostname (from tornado==4.3)
  Downloading backports.ssl_match_hostname-3.7.0.1.tar.gz
  Running setup.py (path:/tmp/pip-build-zLo_HN/backports.ssl-match-hostname/setup.py) egg_info for package backports.ssl-match-hostname

Requirement already satisfied (use --upgrade to upgrade): singledispatch in /usr/local/lib/python2.7/dist-packages (from tornado==4.3)
Downloading/unpacking certifi (from tornado==4.3)
  Downloading certifi-2018.11.29-py2.py3-none-any.whl (154kB): 154kB downloaded
Requirement already satisfied (use --upgrade to upgrade): backports-abc>=0.4 in /usr/local/lib/python2.7/dist-packages (from tornado==4.3)
Installing collected packages: tornado, backports.ssl-match-hostname, certifi
  Found existing installation: tornado 5.0.2
    Uninstalling tornado:
      Successfully uninstalled tornado
  Running setup.py install for tornado
    building 'tornado.speedups' extension
    x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -I/usr/include/python2.7 -c tornado/speedups.c -o build/temp.linux-x86_64-2.7/tornado/speedups.o
    tornado/speedups.c:2:20: fatal error: Python.h: No such file or directory
     #include <Python.h>
                        ^
    compilation terminated.
    /tmp/pip-build-zLo_HN/tornado/setup.py:94: UserWarning:
    ********************************************************************
    WARNING: The tornado.speedups extension module could not
    be compiled. No C extensions are essential for Tornado to run,
    although they do result in significant speed improvements for
    websockets.
    The output above this warning shows how the compilation failed.

    Here are some hints for popular operating systems:

    If you are seeing this message on Linux you probably need to
    install GCC and/or the Python development package for your
    version of Python.

    Debian and Ubuntu users should issue the following command:

        $ sudo apt-get install build-essential python-dev

    RedHat, CentOS, and Fedora users should issue the following command:

        $ sudo yum install gcc python-devel

    If you are seeing this message on OSX please read the documentation
    here:

    http://api.mongodb.org/python/current/installation.html#osx
    ********************************************************************

      "The output above "
    command 'x86_64-linux-gnu-gcc' failed with exit status 1

    no previously-included directories found matching 'docs/build'
    warning: no files found matching 'tornado/test/README'
  Running setup.py install for backports.ssl-match-hostname

Successfully installed tornado backports.ssl-match-hostname certifi
Cleaning up...
phiresky commented 5 years ago

I can confirm that running that in /opt in the container before running start fixed this problem for me:

apt-get install build-essential python-dev
pip install tornado==4.3 --upgrade --force-reinstall
../start.sh -y /opt/models/kaldi_tuda_de_nnet3_chain2.yaml

Logs before looked like this:

2019-10-16 16:43:59 -   DEBUG:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Checking that decoder hasn't been silent for more than 15 seconds
2019-10-16 16:44:00 -   DEBUG:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Checking that decoder hasn't been silent for more than 15 seconds
2019-10-16 16:44:01 -   DEBUG:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Checking that decoder hasn't been silent for more than 15 seconds
2019-10-16 16:44:02 -   DEBUG:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Checking that decoder hasn't been silent for more than 15 seconds
2019-10-16 16:44:03 -   DEBUG:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Checking that decoder hasn't been silent for more than 15 seconds
2019-10-16 16:44:04 - WARNING:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: More than 15 seconds from last decoder hypothesis update, cancelling
2019-10-16 16:44:04 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Master disconnected before decoder reached EOS?
2019-10-16 16:44:04 -    INFO:   decoder2: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Sending EOS to pipeline in order to cancel processing
2019-10-16 16:44:04 -    INFO:   decoder2: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Cancelled pipeline
2019-10-16 16:44:04 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:05 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:06 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:07 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:08 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
[...]
2019-10-16 16:44:32 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:33 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Waiting for EOS from decoder
2019-10-16 16:44:34 -    INFO:   __main__: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Giving up waiting after 31 tries
2019-10-16 16:44:34 -    INFO:   decoder2: 2e87035a-72c0-4b97-8e78-4063a0f5aee6: Resetting decoder state

both curl:

curl -T int5.wav http://localhost:8080/client/dynamic/recognize

and the python websocket client would just hang and not return any data.

I think this problem should be reopened since it still happens on jcsilva/docker-kaldi-gstreamer-server:latest as of now.

hezhenke commented 2 years ago

I meet the same problem,your experience is very helpful to me.I fallow the step "pip install tornado==4.3" before I start the server,I work.