OpenVoiceOS/ovos-dinkum-listener

"log_level" option not honorred

goldyfruit opened this issue · 4 comments

Even if "log_level": "INFO" is set into the configuration, DinKum still display DEBUG messages.

2023-05-27 14:13:00.933 - OVOS - ovos_config.models:load_local:105 - DEBUG - Configuration /Users/goldyfruit/Virtualenvs/ovos/lib/python3.11/site-packages/ovos_config/mycroft.conf loaded
2023-05-27 14:13:00.944 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/etc/mycroft/mycroft.conf' not defined, skipping
2023-05-27 14:13:00.954 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/Users/goldyfruit/.config/mycroft/web_cache.json' not defined, skipping
2023-05-27 14:13:01.075 - OVOS - ovos_config.models:load_local:105 - DEBUG - Configuration /Users/goldyfruit/.config/mycroft/mycroft.conf loaded
2023-05-27 14:13:01.086 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/etc/xdg/mycroft/mycroft.conf' not defined, skipping
2023-05-27 14:13:01.096 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/Users/goldyfruit/.mycroft/mycroft.conf' not defined, skipping
2023-05-27 14:13:01.136 - OVOS - ovos_utils.configuration:get_xdg_config_save_path:141 - WARNING - configuration moved to the `ovos_config` package. This submodule will be removed in ovos_utils 0.1.0
2023-05-27 14:13:01.200 - OVOS - ovos_utils.configuration:get_xdg_base:76 - WARNING - configuration moved to the `ovos_config` package. This submodule will be removed in ovos_utils 0.1.0
2023-05-27 14:13:01.492 - OVOS - ovos_dinkum_listener.service:__init__:123 - INFO - Starting Voice Service
2023-05-27 14:13:01.525 - OVOS - ovos_dinkum_listener.service:on_alive:58 - INFO - DinkumVoiceService is alive.
2023-05-27 14:13:01.526 - OVOS - ovos_dinkum_listener.service:_before_start:280 - INFO - Starting service...
2023-05-27 14:13:01.527 - OVOS - ovos_bus_client.conf:load_message_bus_config:19 - DEBUG - Loading message bus configs
2023-05-27 14:13:01.528 - OVOS - ovos_dinkum_listener.service:_connect_to_bus:365 - DEBUG - Starting bus connection
2023-05-27 14:13:01.534 - OVOS - ovos_bus_client.client.client:on_open:85 - DEBUG - Connected
2023-05-27 14:13:01.541 - OVOS - ovos_bus_client.session:from_message:184 - DEBUG - Creating default session on reference
2023-05-27 14:13:01.543 - OVOS - ovos_bus_client.session:reset_default_session:225 - INFO - New Default Session Start: e07ae434-7e00-44fd-aa99-e5ca32567319
2023-05-27 14:13:01.689 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/Users/goldyfruit/.config/mycroft/web_cache.json' not defined, skipping
2023-05-27 14:13:01.690 - OVOS - ovos_dinkum_listener.service:_connect_to_bus:372 - INFO - Connected to Mycroft Core message bus
2023-05-27 14:13:02.015 - OVOS - ovos_plugin_manager.microphone:create:71 - DEBUG - Loaded microphone plugin ovos-microphone-plugin-sounddevice
2023-05-27 14:13:02.037 - OVOS - ovos_dinkum_listener.plugins:load_stt_module:60 - DEBUG - Using FakeStreamingSTT wrapper
2023-05-27 14:13:02.045 - OVOS - ovos_dinkum_listener.service:_before_start:280 - INFO - Starting service...
2023-05-27 14:13:02.192 - OVOS - ovos_config.models:load_local:111 - DEBUG - Configuration '/Users/goldyfruit/.config/mycroft/web_cache.json' not defined, skipping
2023-05-27 14:13:02.194 - OVOS - ovos_dinkum_listener.service:_connect_to_bus:372 - INFO - Connected to Mycroft Core message bus
2023-05-27 14:13:02.200 - OVOS - ovos_microphone_plugin_sounddevice:start:56 - DEBUG - Opening microphone (device=default, rate=16000, width=2, channels=1)
2023-05-27 14:13:02.201 - OVOS - ovos_microphone_plugin_sounddevice:find_input_device:43 - INFO - Searching for input device: default
2023-05-27 14:13:02.202 - OVOS - ovos_microphone_plugin_sounddevice:find_input_device:44 - DEBUG - Devices: 
2023-05-27 14:13:02.202 - OVOS - ovos_microphone_plugin_sounddevice:find_input_device:48 - DEBUG -    Built-in Microphone
2023-05-27 14:13:02.203 - OVOS - ovos_microphone_plugin_sounddevice:find_input_device:48 - DEBUG -    Built-in Output
2023-05-27 14:13:02.268 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:88 - INFO - creating hotword engines
2023-05-27 14:13:02.270 - OVOS - ovos_plugin_manager.wakewords:load_module:147 - INFO - Loading "hey_mycroft_vosk" wake word via ovos-ww-plugin-vosk with config: {'module': 'ovos-ww-plugin-vosk', 'samples': ['hey mycroft', 'hey microsoft', 'hey mike roft', 'hey minecraft'], 'rule': 'fuzzy', 'listen': True, 'fallback_ww': 'hey_mycroft_pocketsphinx', 'active': True}
2023-05-27 14:13:02.358 - OVOS - ovos_plugin_manager.utils:find_plugins:111 - DEBUG - Failed to load plugin entry point EntryPoint(name='ovos-precise-lite', value='ovos_ww_plugin_precise_lite:PreciseLiteHotwordPlugin', group='mycroft.plugin.wake_word'): No module named 'tflite_runtime'
2023-05-27 14:13:02.360 - OVOS - ovos_plugin_manager.utils:find_plugins:111 - DEBUG - Failed to load plugin entry point EntryPoint(name='ovos-ww-plugin-precise-lite', value='ovos_ww_plugin_precise_lite:PreciseLiteHotwordPlugin', group='mycroft.plugin.wake_word'): No module named 'tflite_runtime'
2023-05-27 14:13:02.409 - OVOS - ovos_plugin_manager.wakewords:load_module:154 - INFO - Loaded the Wake Word hey_mycroft_vosk with module ovos-ww-plugin-vosk
LOG (VoskAPI:ReadDataFiles():model.cc:213) Decoding params beam=10 max-active=3000 lattice-beam=2
LOG (VoskAPI:ReadDataFiles():model.cc:216) Silence phones 1:2:3:4:5:6:7:8:9:10
LOG (VoskAPI:RemoveOrphanNodes():nnet-nnet.cc:948) Removed 0 orphan nodes.
LOG (VoskAPI:RemoveOrphanComponents():nnet-nnet.cc:847) Removing 0 orphan components.
LOG (VoskAPI:ReadDataFiles():model.cc:248) Loading i-vector extractor from /Users/goldyfruit/.local/share/vosk/vosk-model-small-en-us-0/ivector/final.ie
LOG (VoskAPI:ComputeDerivedVars():ivector-extractor.cc:183) Computing derived variables for iVector extractor
LOG (VoskAPI:ComputeDerivedVars():ivector-extractor.cc:204) Done.
LOG (VoskAPI:ReadDataFiles():model.cc:282) Loading HCL and G from /Users/goldyfruit/.local/share/vosk/vosk-model-small-en-us-0/graph/HCLr.fst /Users/goldyfruit/.local/share/vosk/vosk-model-small-en-us-0/graph/Gr.fst
LOG (VoskAPI:ReadDataFiles():model.cc:303) Loading winfo /Users/goldyfruit/.local/share/vosk/vosk-model-small-en-us-0/graph/phones/word_boundary.int
LOG (VoskAPI:Recognizer():recognizer.cc:63) ["hey mycroft", "hey microsoft", "hey mike roft", "hey minecraft", "[unk]"]
WARNING (VoskAPI:Recognizer():recognizer.cc:84) Ignoring word missing in vocabulary: 'mycroft'
WARNING (VoskAPI:Recognizer():recognizer.cc:84) Ignoring word missing in vocabulary: 'roft'
LOG (VoskAPI:Estimate():language_model.cc:142) Estimating language model with ngram-order=2, discount=0.5
LOG (VoskAPI:OutputToFst():language_model.cc:209) Created language model with 6 states and 13 arcs.
2023-05-27 14:13:02.845 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:138 - INFO - Loading hotword: hey_mycroft_vosk with engine: <ovos_ww_plugin_vosk.VoskWakeWordPlugin object at 0x110777d50>
2023-05-27 14:13:02.846 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:start:150 - INFO - Listening mode: ListeningMode.WAKEWORD
2023-05-27 14:13:02.847 - OVOS - ovos_dinkum_listener.service:register_event_handlers:315 - DEBUG - Messagebus events registered
2023-05-27 14:13:02.848 - OVOS - ovos_dinkum_listener.service:on_started:62 - INFO - DinkumVoiceService started.
2023-05-27 14:13:02.848 - OVOS - ovos_dinkum_listener.service:run:250 - DEBUG - Service started
2023-05-27 14:13:02.849 - OVOS - ovos_dinkum_listener.service:on_ready:54 - INFO - DinkumVoiceService is ready.
2023-05-27 14:13:02.850 - OVOS - ovos_dinkum_listener.service:run:254 - INFO - Service ready
2023-05-27 14:13:02.850 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:run:174 - INFO - Starting loop in mode: ListeningMode.WAKEWORD

I don't know what changed but now it's OK.

Re-opening as I see the other the same behaviour the other way, I want to enabled DEBUG but I only got INFO.

The service doesn't seem to load the configuration file

If I run ovos-config show into the container, I got the correct configuration.

ovos-config get -k log_level
Value: DEBUG, found in /log_level

Other services log correctly.