Mycroft on FreeBSD


#41

I believe he means his mic and sound are not working.

Does freebsd uses pulseaudio?


#42

Sound in general works, Mycroft plays music. But he does not speak, and does not listen to commands.

Where to look? In /var/spool/log/audio.log?
Or any config docs?


#43

Hey there @Guru, a few thoughts;

Logs

Logs should be at /var/log/mycroft on your system. The key logs here would be;

  • voice.log - this shows voice output or intended voice output
  • audio.log- this shows audio output, such as music or streaming

Not hearing commands

If Mycroft is not hearing commands, it’s likely that the microphone is not being recognised.

  • Firstly, try alsamixer to see if your sources are selected
  • You may need to install pulseaudio

If the CLI is accepting commands, but nothing is being spoken, then check the skills.log for Python errors.

This definitely sounds like a microphone issue.


#44

I got the voice input working:

18:04:21.919 - AlarmSkill - INFO - on ended...
18:04:21.911 - __main__:handle_record_end:40 - INFO - End Recording...
~~~~21.918 - mycroft.session:get:76 - INFO - New Session Start: 109a8642-67bd-4f18-a35f-942a499e08e6
18:04:21.922 - __main__:handle_wakeword:56 - INFO - Wakeword Detected: hey mycroft
18:04:24.163 - __main__:handle_utterance:61 - INFO - Utterance: ['how is the weather in berlin']
  ^--- NEWEST ---^ 
History ========================================    Log Output Legend ================ Mic Level ===
 how is the weather in berlin                       DEBUG output                     
 >> temperature, 37 °F (wind chill: 34 °F),         skills.log, other                
    conditions, cloudy, relative humidity, 93%      voice.log                        
    (dew point: 36 °F), wind speed, 5 mph, (44                                       
    minutes ago)                                                                     
                                                                                     
                                                                                     
                                                                                         --- 177.91
                                                                                     
                                                                                     126  *        
Input (':' for command, Ctrl+C to quit) =============================================     *        
>                                                                                         *        

Will look for the voice of Mycraft.

In voice.log we have:

18:04:24.163 - __main__:handle_utterance:61 - INFO - Utterance: ['how is the weather in berlin']
18:05:55.679 - mycroft.messagebus.client.ws:on_error:74 - WARNING - Could not send message because connection has closed
18:05:55.695 - mycroft.messagebus.client.ws:on_error:83 - ERROR - Exception closing websocket: Exception("Uncaught 'error' event.",)
18:05:55.698 - mycroft.messagebus.client.ws:on_error:85 - WARNING - WS Client will reconnect in 5 seconds.
18:06:00.705 - mycroft.messagebus.client.ws:on_error:76 - ERROR - === ConnectionRefusedError(61, 'Connection refused') ===

#45

Hi @Guru - those lines in the log indicate that the Mycroft services have shut down after the how is the weather utterance. This might happen if there is an error in the Skill.

What log lines are there in the skill.log file for around the same timestamp? Are there any Python errors or anything that would explain Mycroft shutting down?


#46

In skill.log for this action we have:

18:04:22.019 - SKILLS - DEBUG - {"context": null, "type": "recognizer_loop:wakeword", "data": {"session": "109a8642-67bd-4f18-a35f-942a499e08e6", "utterance": "hey mycroft"}}
18:04:24.169 - SKILLS - DEBUG - {"context": {"ident": "1542992661.92340141497061289956319986", "client_name": "mycroft_listener"}, "type": "recognizer_loop:utterance", "data": {"session": "109a8642-67bd-4f18-a35f-942a499e08e6", "utterances": ["how is the weather in berlin"], "lang": "en-US"}}
18:04:24.209 - SKILLS - DEBUG - {"type": "intent_failure", "data": {"utterance": "how is the weather in berlin", "lang": "en-US"}, "context": {"client_name": "mycroft_listener", "ident": "1542992661.92340141497061289956319986"}}
18:04:24.213 - SKILLS - DEBUG - {"type": "mycroft.skill.handler.start", "data": {"handler": "fallback"}, "context": {"client_name": "mycroft_listener", "ident": "1542992661.92340141497061289956319986"}}
18:04:24.215 - mycroft.skills.padatious_service:handle_fallback:133 - DEBUG - Padatious fallback attempt: how is the weather in berlin
18:04:24.228 - WolframAlphaSkill - DEBUG - WolframAlpha fallback attempt: how is the weather in berlin
18:04:24.229 - WolframAlphaSkill - DEBUG - Querying WolframAlpha: how is the weather in berlin
18:04:24.239 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
18:04:24.256 - SKILLS - DEBUG - {"type": "enclosure.mouth.think", "data": {}, "context": null}
18:04:30.212 - SKILLS - DEBUG - {"type": "mycroft-date-time.mycroftai:TimeSkillupdate_display", "data": {}, "context": null}
18:04:33.325 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/wa?input=how+is+the+weather+in+berlin HTTP/1.1" 200 13594
18:04:33.482 - SKILLS - DEBUG - {"type": "speak", "data": {"utterance": "temperature, 37 \u00b0F (wind chill: 34 \u00b0F), conditions, cloudy, relative humidity, 93% (dew point: 36 \u00b0F), wind speed, 5 mph, (44 minutes ago)", "expect_response": false}, "context": {"client_name": "mycroft_listener", "ident": "1542992661.92340141497061289956319986"}}
18:04:33.584 - SKILLS - DEBUG - {"type": "mycroft.skill.handler.complete", "data": {"handler": "fallback", "fallback_handler": "WolframAlphaSkill.handle_fallback"}, "context": {"client_name": "mycroft_listener", "ident": "1542992661.92340141497061289956319986"}}
18:04:35.236 - SKILLS - DEBUG - {"type": "mycroft-reminder.mycroftai:reminder", "data": {}, "context": null}
18:04:38.357 - SKILLS - DEBUG - {"type": "enclosure.eyes.blink", "data": {"side": "b"}, "context": null}
18:04:38.451 - SKILLS - DEBUG - {"type": "recognizer_loop:audio_output_start", "data": {}, "context": null}
18:04:40.271 - SKILLS - DEBUG - {"type": "mycroft-date-time.mycroftai:TimeSkillupdate_display", "data": {}, "context": null}
18:04:45.211 - SKILLS - DEBUG - {"type": "recognizer_loop:audio_output_end", "data": {}, "context": null}
18:04:45.212 - SKILLS - DEBUG - {"type": "enclosure.eyes.blink", "data": {"side": "b"}, "context": null}
18:04:50.331 - SKILLS - DEBUG - {"type": "mycroft-date-time.mycroftai:TimeSkillupdate_display", "data": {}, "context": null}
18:04:51.808 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
18:04:52.565 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/e7a4c241-70e1-44c2-8203-0667894036e4/skill HTTP/1.1" 304 0
18:04:54.109 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
18:04:54.926 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/e7a4c241-70e1-44c2-8203-0667894036e4/skill HTTP/1.1" 304 0

#47

thanks @guru - all of those log file entries look fine - it’s what I would expect to see if a Weather request was made. That is, there are no error messages showing.

The only thing I can think of is that one of the Mycroft services is sending an illegal command and the operating system is terminating the process.

Is there anything in dmesg about Mycroft? I’m assuming that FreeBSD syslogs to dmesg - I could be wrong.


#48

I did a fresh test. On start of the cli (at 19:58:59) before any request to Mycroft we have some line in audio.log which are perhaps related to our problem:

19:59:04.070 - __main__:main:38 - INFO - Starting Audio Services
19:59:04.082 - mycroft.messagebus.client.ws:on_open:62 - INFO - Connected
19:59:04.098 - mycroft.audio.audioservice:get_services:58 - INFO - Loading services from /usr/home/guru/Mycroft-test/mycroft-core/mycroft/audio/services/
19:59:04.107 - mycroft.audio.audioservice:load_services:102 - INFO - Loading chromecast
19:59:09.969 - mycroft.audio.audioservice:load_services:102 - INFO - Loading mopidy
19:59:09.980 - mycroft.audio.audioservice:load_services:102 - INFO - Loading mplayer
19:59:10.091 - mplayer__init__:<module>:20 - ERROR - install py_mplayer with pip install git+https://github.com/JarbasAl/py_mplayer
19:59:10.094 - mycroft.audio.audioservice:load_services:108 - ERROR - Failed to import module mplayer
ImportError("No module named 'Queue'",)
19:59:10.097 - mycroft.audio.audioservice:load_services:102 - INFO - Loading simple
19:59:10.127 - mycroft.audio.audioservice:load_services:102 - INFO - Loading vlc
19:59:10.141 - mycroft.audio.audioservice:load_services:108 - ERROR - Failed to import module vlc
NotImplementedError('/usr/home/guru/Mycroft-test/mycroft-core/mycroft/audio/__main__.py: freebsd12 not supported',)
19:59:10.145 - mycroft.audio.audioservice:load_services_callback:170 - INFO - Finding default backend...
19:59:10.147 - mycroft.audio.audioservice:load_services_callback:174 - INFO - Found local

at 19:59:57.076, when the voice utterance about the weather should be answered, we see in audio.log:

19:59:57.076 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
19:59:57.076 - urllib3.connectionpool - DEBUG - Starting new HTTPS connection (1): api.mycroft.ai:443
19:59:57.727 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/e7a4c241-70e1-44c2-8203-0667894036e4/subscription HTTP/1.1" 200 114
19:59:57.727 - urllib3.connectionpool - DEBUG - https://api.mycroft.ai:443 "GET /v1/device/e7a4c241-70e1-44c2-8203-0667894036e4/subscription HTTP/1.1" 200 114
  Carnegie Mellon University, Copyright (c) 1999-2011, all rights reserved
  mimic developers, Copyright (c) 2016, all rights reserved
  version: mimic-1.2.0.2 ()
19:59:57.879 - mycroft.audio.speech:mute_and_speak:119 - INFO - Speak: temperature, 37 °F (wind chill: 33 °F), conditions, cloudy, relative humidity, 70% (dew point: 28 °F), wind speed, 6 mph, (40 minutes ago)
Path  in link /home/guru/.config/pulse/41807f6b8965d38bc4110b3a55be1713-runtime is not absolute.
W: [(null)] caps.c: Normally all extra capabilities would be dropped now, but that's impossible because PulseAudio was built without capabilities support.
Connection failure: Connection refused
pa_context_connect() failed: Connection refused

The only lines in /var/log/messages after the start of the cli are (and perhaps also related to the problem:)::

Nov 26 19:59:03 c720-r314251 kernel: feeder_init(0xfffff8001347a480) on feeder_matrix returned 22
Nov 26 19:59:03 c720-r314251 kernel: pcm0: feeder_build_matrix(): can't add feeder_matrix
Nov 26 19:59:42 c720-r314251 pulseaudio[2819]: [(null)] core-util.c: Path  in link /home/guru/.config/pulse/41807f6b8965d38bc4110b3a55be1713-runtime is not absolute.
Nov 26 19:59:42 c720-r314251 pulseaudio[2817]: [(null)] main.c: Daemon startup failed.

#49

So, this line is happening when vlc is imported. mplayer isn’t loading either because the Queues module is not loading - these are both used for playback, which is why playback is not occurring.

Is there any possibility you can upgrade to a newer version of FreeBSD?


#50

I was thinking that the no speech problem is caused by the not working pulseaudio daemon… In any case,
I will try to update to a newer version after Christmas. I’m on vacation from the beginning of next week in any case.

Thanks for all your support.


#51

You’re very welcome - the no speech could be caused by the not working Pulseaudio daemon - which in turn is throwing this error :wink:

Hope you have a lovely vacation!


#52

The pulseaudio is not starting at all (it’s crashing), also outside of Mycroft, see here:
https://lists.freebsd.org/pipermail/freebsd-questions/2018-November/283436.html


#53

Hmmm :frowning: Sounds like this is more an issue of PulseAudio on FreeBSD rather than a Mycroft issue.


#54

Of course, this is within FreeBSD (or the used ported software).


#55

I have now updated my FreeBSD box to the bleeding edge (all from December 23, kernel and ports) and recompiled everything of Mycroft. Now cli is unwilling to start, it gives:

...
Starting cli
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/runpy.py", line 183, in _run_module_as_main
    mod_name, mod_spec, code = _get_module_details(mod_name, _Error)
  File "/usr/local/lib/python3.6/runpy.py", line 109, in _get_module_details
    __import__(pkg_name)
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/__init__.py", line 17, in <module>
    from mycroft.api import Api
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/api/__init__.py", line 23, in <module>
    from mycroft.configuration import Configuration
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/configuration/__init__.py", line 15, in <module>
    from .config import Configuration, LocalConf, RemoteConf
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/configuration/config.py", line 23, in <module>
    from mycroft.util.json_helper import load_commented_json, merge_dict
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/util/__init__.py", line 39, in <module>
    from mycroft.util.parse import extract_datetime, extract_number, normalize
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/util/parse.py", line 18, in <module>
    from mycroft.util.time import now_local
  File "/usr/home/guru/Mycroft-test/mycroft-core/mycroft/util/time.py", line 18, in <module>
    from dateutil.tz import gettz, tzlocal
ModuleNotFoundError: No module named 'dateutil'

The followin py36 ports are installed:

root@c720-r342378:/usr/PKGDIR.20181223 # python3 --version
Python 3.6.7
root@c720-r342378:/usr/PKGDIR.20181223 # pkg info | grep py36
py36-cairo-1.14.1              Python 2 bindings for Cairo
py36-dateutil-2.7.3            Extensions to the standard Python datetime module
py36-dateutils-0.6.6_1         Various utilities for working with date and datetime objects
py36-gobject3-3.28.3           Common files for the Python bindings for GObject
py36-pytz-2018.7,1             World Timezone Definitions for Python
py36-setuptools-40.6.2         Python packages installer
py36-six-1.12.0                Python 2 and 3 compatibility utilities

What is missing?


#56

Is this using a venv? If so is that the results from the venv?


#57

I sourced before starting . ./venv-activate.sh. Is this your question? If not, please clarify.


#58

yes…though it’s not showing the (venv) bit I’d usually expect to see there. If, as the mycroft user, you run python3, then do “import dateutil”, does that error out?


#59
$ python3
Python 3.6.7 (default, Dec 24 2018, 12:25:59) 
[GCC 4.2.1 Compatible FreeBSD Clang 7.0.1 (tags/RELEASE_701/final 349250)] on freebsd13
Type "help", "copyright", "credits" or "license" for more information.
>>> import dateutil
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ModuleNotFoundError: No module named 'dateutil'

#60

I mean, that’s pretty straightforward then. It can’t load that module, but not clear why. Try pip3 install dateutil (might be python-dateutil) as the mycroft user in the venv?