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.

Sign up for GitHub

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

Jump to bottom

PHAL doesn't connect to the message bus. #32

Closed
goldyfruit opened this issue Sep 6, 2023 · 1 comment
Closed

PHAL doesn't connect to the message bus. #32

goldyfruit opened this issue Sep 6, 2023 · 1 comment

Comments

@goldyfruit
Copy link 

2023-09-05 13:02:05.898 - OVOS - ovos_plugin_manager.ocp:load:54 - INFO - Loaded OCP plugin: ovos-ocp-files-plugin
2023-09-05 13:02:06.345 - OVOS - ovos_plugin_manager.ocp:load:54 - INFO - Loaded OCP plugin: ovos-ocp-m3u-plugin
2023-09-05 13:02:06.790 - OVOS - ovos_plugin_manager.ocp:load:54 - INFO - Loaded OCP plugin: ovos-ocp-news-plugin
2023-09-05 13:02:07.234 - OVOS - ovos_plugin_manager.ocp:load:54 - INFO - Loaded OCP plugin: ovos-ocp-rss-plugin
2023-09-05 13:02:08.306 - OVOS - hivemind_bus_client.client:connect:116 - INFO - Connecting to Hivemind
2023-09-05 13:02:08.434 - OVOS - hivemind_bus_client.protocol:bind:99 - INFO - Initializing HiveMindSlaveInternalProtocol
2023-09-05 13:02:08.443 - OVOS - hivemind_bus_client.protocol:bind:102 - INFO - registering protocol handlers
2023-09-05 13:02:13.476 - OVOS - hivemind_bus_client.protocol:start_handshake:139 - INFO - hivemind does not support binarization protocol
2023-09-05 13:02:13.844 - OVOS - hivemind_bus_client.protocol:handle_handshake:169 - INFO - HANDSHAKE: {'envelope': '7073494679785072afb03ffa3a1b3c1b3c353c0fb1b2c76e', 'binarize': False}
2023-09-05 13:02:13.852 - OVOS - hivemind_bus_client.protocol:receive_handshake:152 - INFO - Received password envelope
2023-09-05 13:02:14.373 - OVOS - ovos_audio.service:__init__:49 - INFO - Starting Audio Service
2023-09-05 13:02:14.382 - OVOS - ovos_audio.service:on_started:31 - INFO - Audio service started.
2023-09-05 13:02:14.435 - OVOS - ovos_config.utils:__init__:21 - WARNING - Deprecation version=0.1.0. Caller=ovos_config.config:283. Import from ovos_utils.file_utils directly
2023-09-05 13:02:14.691 - OVOS - ovos_audio.service:_maybe_reload_tts:291 - INFO - (re)loading TTS engine
2023-09-05 13:02:14.898 - OVOS - ovos_utils.configuration:get_xdg_base - WARNING - Deprecation version=0.1.0. Caller=ovos_tts_plugin_mimic:93. configuration moved to the `ovos_config` package.
2023-09-05 13:02:15.001 - OVOS - ovos_utils.configuration:read_mycroft_config - WARNING - Deprecation version=0.1.0. Caller=ovos_tts_plugin_mimic:106. configuration moved to the `ovos_config` package.
2023-09-05 13:02:15.027 - OVOS - ovos_plugin_manager.tts:create:197 - INFO - Found plugin ovos-tts-plugin-server
2023-09-05 13:02:15.054 - OVOS - ovos_utils.file_utils:resolve_resource_file:153 - WARNING - Deprecation version=0.1.0. Caller=ovos_plugin_manager.templates.tts:526. Expected a dict config and got None.
2023-09-05 13:02:20.068 - OVOS - ovos_plugin_manager.tts:create:200 - INFO - Loaded plugin ovos-tts-plugin-server
2023-09-05 13:02:20.075 - OVOS - ovos_audio.service:_maybe_reload_tts:310 - INFO - (re)loading fallback TTS engine
2023-09-05 13:02:20.159 - OVOS - ovos_plugin_manager.tts:create:197 - INFO - Found plugin ovos-tts-plugin-mimic3-server
2023-09-05 13:02:20.175 - OVOS - ovos_utils.file_utils:resolve_resource_file:153 - WARNING - Deprecation version=0.1.0. Caller=ovos_plugin_manager.templates.tts:526. Expected a dict config and got None.
2023-09-05 13:02:20.467 - OVOS - ovos_plugin_manager.tts:create:200 - INFO - Loaded plugin ovos-tts-plugin-mimic3-server
2023-09-05 13:02:20.547 - OVOS - ovos_audio.audio:load_services:94 - INFO - Loading audio service plugin: ovos_audio_simple
2023-09-05 13:02:20.553 - OVOS - ovos_audio.audio:find_default:69 - WARNING - default backend set to OCP, but OCP is disabled
2023-09-05 13:02:20.559 - OVOS - ovos_audio.audio:find_default:71 - INFO - Finding default audio backend...
2023-09-05 13:02:20.565 - OVOS - ovos_audio.audio:find_default:79 - INFO - no default found
2023-09-05 13:02:20.657 - OVOS - ovos_audio.service:on_alive:27 - INFO - Audio service is alive.
2023-09-05 13:02:20.666 - OVOS - ovos_dinkum_listener.service:__init__:123 - INFO - Starting Voice Service
2023-09-05 13:02:20.672 - OVOS - hivemind_voice_satellite.service:on_alive:15 - INFO - HiveMind Voice Satellite alive.
2023-09-05 13:02:20.678 - OVOS - ovos_dinkum_listener.service:_before_start:293 - INFO - Starting service...
2023-09-05 13:02:20.765 - OVOS - ovos_audio.service:run:238 - WARNING - No audio backends loaded! Audio playback is not available
2023-09-05 13:02:20.781 - OVOS - ovos_audio.service:run:240 - INFO - Running audio service in TTS only mode
2023-09-05 13:02:20.786 - OVOS - ovos_audio.service:on_ready:23 - INFO - Audio service is ready.
2023-09-05 13:02:22.894 - OVOS - hivemind_voice_satellite.service:on_alive:15 - INFO - HiveMind Voice Satellite alive.
2023-09-05 13:02:22.898 - OVOS - ovos_dinkum_listener.service:_before_start:293 - INFO - Starting service...
2023-09-05 13:02:22.959 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:108 - INFO - creating hotword engines
2023-09-05 13:02:22.993 - OVOS - ovos_workshop.skills.mycroft_skill:__call__:67 - WARNING - skill_id should be a kwarg, please update PHAL
2023-09-05 13:02:22.998 - OVOS - ovos_plugin_manager.wakewords:load_module:165 - INFO - Loading "hey_mycroft" wake word via ovos-ww-plugin-precise-lite with config: {'module': 'ovos-ww-plugin-precise-lite', 'model': 'https://github.com/OpenVoiceOS/precise-lite-models/raw/master/wakewords/en/hey_mycroft.tflite', 'expected_duration': 3, 'trigger_level': 3, 'sensitivity': 0.5, 'listen': True, 'fallback_ww': 'hey_mycroft_precise'}
2023-09-05 13:02:23.006 - OVOS - ovos_workshop.skills.mycroft_skill:__call__:81 - WARNING - skill initialized without bus!! this is legacy behaviour and requires you to call skill.bind(bus) or skill._startup(skill_id, bus)
bus will be required starting on ovos-core 0.1.0
2023-09-05 13:02:23.079 - OVOS - ovos_bus_client.client.client:on_error:110 - WARNING - Connection Refused. Is Messagebus Service running?
2023-09-05 13:02:23.100 - OVOS - ovos_bus_client.client.client:on_error:119 - ERROR - Exception closing websocket at ws://0.0.0.0:8181/core: [Errno 111] Connection refused
2023-09-05 13:02:23.124 - OVOS - ovos_bus_client.client.client:on_error:121 - WARNING - Message Bus Client will reconnect in 5.0 seconds.
2023-09-05 13:02:23.131 - OVOS - ovos_workshop.skills.base:is_classic_core:85 - WARNING - Deprecation version=0.1.0. Caller=ovos_workshop.skills.mycroft_skill:168. Support for `mycroft_core` will be deprecated
2023-09-05 13:02:23.322 - OVOS - ovos_plugin_manager.wakewords:load_module:172 - INFO - Loaded the Wake Word hey_mycroft with module ovos-ww-plugin-precise-lite
INFO: Created TensorFlow Lite XNNPACK delegate for CPU.
2023-09-05 13:02:23.347 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:158 - INFO - Loading hotword: hey_mycroft with engine: <ovos_ww_plugin_precise_lite.PreciseLiteHotwordPlugin object at 0x7f55be5550>
2023-09-05 13:02:23.356 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:189 - WARNING - No wakeup words loaded
2023-09-05 13:02:23.363 - OVOS - ovos_dinkum_listener.voice_loop.hotwords:load_hotword_engines:191 - WARNING - No stop words loaded
2023-09-05 13:02:23.382 - OVOS - ovos_workshop.skills.base:is_classic_core:85 - WARNING - Deprecation version=0.1.0. Caller=ovos_workshop.skills.ovos:39. Support for `mycroft_core` will be deprecated
2023-09-05 13:02:23.385 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:start:166 - INFO - Listening mode: ListeningMode.WAKEWORD
2023-09-05 13:02:23.411 - OVOS - ovos_utils.gui:get_ui_directories:94 - INFO - Checking for legacy UI directories
2023-09-05 13:02:23.478 - OVOS - ovos_workshop.skills.base:is_classic_core:85 - WARNING - Deprecation version=0.1.0. Caller=ovos_workshop.skills.mycroft_skill:148. Support for `mycroft_core` will be deprecated
2023-09-05 13:02:23.481 - ovos.PHAL - WARNING - Tried to initialize ovos.PHAL multiple times, ignoring
2023-09-05 13:02:23.493 - OVOS - ovos_PHAL.service:on_started:26 - INFO - PHAL is started
2023-09-05 13:02:23.579 - OVOS - hivemind_voice_satellite.service:on_started:11 - INFO - HiveMind Voice Satellite started.
2023-09-05 13:02:23.583 - OVOS - hivemind_voice_satellite.service:on_started:11 - INFO - HiveMind Voice Satellite started.
2023-09-05 13:02:23.597 - OVOS - hivemind_voice_satellite.service:on_ready:7 - INFO - HiveMind Voice Satellite is ready.
2023-09-05 13:02:23.607 - OVOS - ovos_dinkum_listener.service:run:268 - INFO - Service ready
2023-09-05 13:02:23.618 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:run:191 - INFO - Starting loop in mode: ListeningMode.WAKEWORD
2023-09-05 13:02:23.662 - OVOS - ovos_PHAL.service:on_ready:10 - INFO - PHAL is ready.
2023-09-05 13:02:28.135 - OVOS - ovos_bus_client.client.client:on_error:110 - WARNING - Connection Refused. Is Messagebus Service running?
2023-09-05 13:02:28.144 - OVOS - ovos_bus_client.client.client:on_error:119 - ERROR - Exception closing websocket at ws://0.0.0.0:8181/core: [Errno 111] Connection refused
2023-09-05 13:02:28.151 - OVOS - ovos_bus_client.client.client:on_error:121 - WARNING - Message Bus Client will reconnect in 10.0 seconds.
2023-09-05 13:02:34.752 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:run:219 - INFO - Wakeword detected
2023-09-05 13:02:35.898 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:run:249 - INFO - speech finished
2023-09-05 13:02:36.369 - OVOS - ovos_dinkum_listener.voice_loop.voice_loop:_after_cmd:657 - INFO - transcribed: "To what time is it?"
2023-09-05 13:02:36.693 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: skill-ovos-date-time.openvoiceos:handle_query_time
2023-09-05 13:02:36.712 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: mycroft.skill.handler.start
2023-09-05 13:02:36.767 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.active_skill
2023-09-05 13:02:36.793 - OVOS - ovos_audio.service:execute_tts:322 - INFO - Speak: It is one oh two
2023-09-05 13:02:37.064 - OVOS - ovos_audio.utils:report_timing:63 - ERROR - Failed to upload metrics
2023-09-05 13:02:37.084 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: speak
2023-09-05 13:02:37.120 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.events.deactivate
2023-09-05 13:02:37.154 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:37.192 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:37.224 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:37.255 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:37.294 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:37.327 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
Playing WAVE '/home/ovos/.cache/mycroft/OVOSServerTTS/default/en-us/09a291f749a395b326daccc0d8218325.wav' : Signed 16 bit Little Endian, Rate 22050 Hz, Mono
2023-09-05 13:02:38.164 - OVOS - ovos_bus_client.client.client:on_error:110 - WARNING - Connection Refused. Is Messagebus Service running?
2023-09-05 13:02:38.174 - OVOS - ovos_bus_client.client.client:on_error:119 - ERROR - Exception closing websocket at ws://0.0.0.0:8181/core: [Errno 111] Connection refused
2023-09-05 13:02:38.184 - OVOS - ovos_bus_client.client.client:on_error:121 - WARNING - Message Bus Client will reconnect in 20.0 seconds.
2023-09-05 13:02:40.068 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.display
2023-09-05 13:02:45.095 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.reset
2023-09-05 13:02:45.113 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: enclosure.mouth.events.activate
2023-09-05 13:02:45.131 - OVOS - hivemind_bus_client.protocol:handle_bus:196 - INFO - BUS: mycroft.skill.handler.complete
2023-09-05 13:02:58.197 - OVOS - ovos_bus_client.client.client:on_error:110 - WARNING - Connection Refused. Is Messagebus Service running?
2023-09-05 13:02:58.211 - OVOS - ovos_bus_client.client.client:on_error:119 - ERROR - Exception closing websocket at ws://0.0.0.0:8181/core: [Errno 111] Connection refused
2023-09-05 13:02:58.225 - OVOS - ovos_bus_client.client.client:on_error:121 - WARNING - Message Bus Client will reconnect in 40.0 seconds.
@Ramblurr
Copy link

Ramblurr commented Sep 12, 2023 •
edited
Loading

Ok I think I traced this issue down. I added a traceback.print_stack() statement in the constructor of the MessageBusClient

HiveMind-voice-sat - ovos_PHAL.service:on_started:26 - INFO - PHAL is started
HiveMind-voice-sat - ovos_workshop.skills.mycroft_skill:__call__:81 - WARNING - skill initialized without bus!! this is legacy behaviour and requires you to call skill.bind(bus) or skill._startup(skill_id, bus)
bus will be required starting on ovos-core 0.1.0
2023-09-12 17:47:20.070 - HiveMind-voice-sat - ovos_bus_client.client.client:__init__:47 - INFO - XXX MessageBusClient ctor XXX
  File "/home/ovos/.venv/bin/hivemind-voice-sat", line 8, in <module>
    sys.exit(connect())
  File "/home/ovos/.venv/lib/python3.11/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
  File "/home/ovos/.venv/lib/python3.11/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
  File "/home/ovos/.venv/lib/python3.11/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/ovos/.venv/lib/python3.11/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
  File "/home/ovos/.venv/lib/python3.11/site-packages/hivemind_voice_satellite/__main__.py", line 44, in connect
    phal = PHAL(bus=bus)
  File "/home/ovos/.venv/lib/python3.11/site-packages/ovos_workshop/skills/mycroft_skill.py", line 85, in __call__
    return super().__call__(*args, **kwargs)
  File "/home/ovos/.venv/lib/python3.11/site-packages/ovos_PHAL/service.py", line 43, in __init__
    bus = MessageBusClient()
  File "/home/ovos/.venv/lib/python3.11/site-packages/ovos_bus_client/client/client.py", line 48, in __init__
    traceback.print_stack()

This shows that the bus is being stripped in the constructor inheritance chain and then being re-initialized after the super chain is finished

class PHAL(OVOSAbstractApplication):
  def __init__(self, config=None, bus=None,
                 on_ready=on_ready, on_error=on_error,
                 on_stopping=on_stopping, on_started=on_started, on_alive=on_alive,
                 watchdog=lambda: None, skill_id="ovos.PHAL", **kwargs):
        super().__init__(skill_id=skill_id, bus=bus)


class OVOSAbstractApplication(OVOSSkill):
    def __init__(self, skill_id, bus=None, resources_dir=None,
                 lang=None, settings=None, gui=None, enable_settings_manager=False):
        super().__init__(bus=bus, gui=gui, resources_dir=resources_dir,
                         enable_settings_manager=enable_settings_manager)

class OVOSSkill(MycroftSkill):
    def __init__(self, *args, **kwargs):
        super(OVOSSkill, self).__init__(*args, **kwargs)

class MycroftSkill(BaseSkill, metaclass=_SkillMetaclass):
    def __init__(self, name=None, bus=None, use_settings=True, *args, **kwargs):
        super().__init__(name=name, bus=bus, *args, **kwargs)

class _SkillMetaclass(ABCMeta):
    def __call__(cls, *args, **kwargs):

Also the presence of the warning emitted here reinforces my idea.

My guess is the problem is at MycroftSkill layer?

@JarbasAl JarbasAl mentioned this issue Sep 12, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Ramblurr @goldyfruit @JarbasAl