Mark II: bad news url in web UI breaks dinkum-skills.service

[LiberalArtist]

Describe the bug
Asking Hey Mycroft, what time is it? hangs seemingly indefinitely with a swirling blue light. Other times, asking Hey Mycroft, what time is it? causes Mycroft to respond Just a second. and then Beats me..

To Reproduce

(I hope this is a good place to report this issue: I can't find a repository for dinkum-skills.service.)

1. In the web UI at https://account.mycroft.ai/skills, configure the News skill to use the custom URL http://stream.wlrn.mobi/WLRNFMAAC32. Note that this is an HTTP stream, not a podcast feed as the service expects!
2. Allow time for the settings to sync.
3. Say Hey Mycroft, what time is it?
4. Wait indefinitely or hear an error message

Expected behavior
I would expect the News skill to fail gracefully, ideally with a useful error message, and certainly not to interfere with other skills.

Environment (please complete the following information):

• Device type: Mark II

Additional context

I tried clearing the custom setting in the web UI, but /home/mycroft/.config/mycroft/skills/news.mark2/settings.json still has the problematic url.

I gathered the logs below using SSH, but this was the first time I SSHed into the device: I had only used the web UI when this problem started.

After submitting this report, I intend to try to fix the configuration by hand.

Log files

This is the content of /home/mycroft/.config/mycroft/skills/news.mark2/settings.json:

{"station": "not_set", "custom_url": "http://stream.wlrn.mobi/WLRNFMAAC32"}

Here is an excerpt from journalctl -u dinkum-skills.service:

Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:skills:Loading skill news.mark2
Oct 27 21:03:06 localhost.localdomain python[14968]: INFO:mycroft.util.log:/home/mycroft/.config/mycroft/skills/news.mark2/settings.json
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skill.stop
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skills.initialized
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skill.enable_intent
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skill.disable_intent
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skill.set_cross_context
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skill.remove_cross_context
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: mycroft.skills.settings.changed
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: play:query
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: play:start
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: play:stop
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: play:pause
Oct 27 21:03:06 localhost.localdomain python[14968]: DEBUG:mycroft.util.log:Added event: play:resume
Oct 27 21:03:06 localhost.localdomain python[14968]: INFO:news.mark2:Creating custom News Station from Skill settings.
Oct 27 21:04:03 localhost.localdomain systemd[1]: dinkum-skills.service: start operation timed out. Terminating.
Oct 27 21:04:03 localhost.localdomain systemd[1]: dinkum-skills.service: Failed with result 'timeout'.
Oct 27 21:04:03 localhost.localdomain systemd[1]: Failed to start Mycroft service skills.service.

Here is a longer set of logs generated by journalctl -u dinkum-* --since="2022-10-27 20:27:11" --until="2022-10-27 20:27:32":

-- Logs begin at Thu 2019-02-14 10:12:04 UTC, end at Thu 2022-10-27 21:43:08 UTC. --
Oct 27 20:27:11 localhost.localdomain python[378]: DEBUG:mycroft_hotword:Triggered
Oct 27 20:27:11 localhost.localdomain python[378]: DEBUG:voice:Wrote /tmp/mycroft/cache/mycroft_wake_words/151822199100.wav
Oct 27 20:27:11 localhost.localdomain python[378]: DEBUG:voice:Awake!
Oct 27 20:27:11 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Disabled idle timeout
Oct 27 20:27:11 localhost.localdomain python[374]: INFO:mycroft.util.log:Ducked volume
Oct 27 20:27:14 localhost.localdomain python[378]: DEBUG:voice:Wrote /tmp/mycroft/cache/mycroft_utterances/154566956529.wav
Oct 27 20:27:14 localhost.localdomain python[378]: DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): api.mycroft.ai:443
Oct 27 20:27:15 localhost.localdomain python[378]: DEBUG:urllib3.connectionpool:https://api.mycroft.ai:443 "POST /v1/transcribe?lang=en-US&limit=1 HTTP/1.1" 200 36
Oct 27 20:27:15 localhost.localdomain python[378]: INFO:mycroft.util.log:{'transcription': 'what time is it'}
Oct 27 20:27:15 localhost.localdomain python[378]: DEBUG:voice:STT: what time is it
Oct 27 20:27:15 localhost.localdomain python[374]: INFO:mycroft.util.log:Unducked volume
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Current sessions: {}
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Starting session: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Enter handle utterance: message.data:{'utterances': ['what time is it'], 'mycroft_session_id': '9023859f-2de5-41b4-bf84-7b1bfac96cef', 'hotword_audio_uri': 'file:///tmp/mycroft/cache/mycroft_wake_words/151822199100.wav', 'stt_audio_uri': 'file:///tmp/mycroft/cache/mycroft_utterances/154566956529.wav'}, session_id:9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Utterances: [('what time is it',)]
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Padatious Matching confidence > 0.95
Oct 27 20:27:15 localhost.localdomain python[377]: INFO:mycroft.util.log:Padatious match: {'name': 'news.mark2:PlayTheNews.intent', 'sent': 'what time is it', 'matches': {'utterance': 'what time is it'}, 'conf': 0.2827819915653492}
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Trying 2 fallback handler(s) at priority 5
Oct 27 20:27:15 localhost.localdomain python[683]: DEBUG:mycroft.util.log:Added event: fallback-query.mark2:QuestionQueryTimeout
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Continuing session: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Disabled idle timeout
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Completed action for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: MessageAction(message_type='question:query', data={'mycroft_session_id': '9023859f-2de5-41b4-bf84-7b1bfac96cef', 'phrase': 'what time is it'}, delay=0.0)
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Handled by fallback skill fallback-query.mark2 at priority 5
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Completed action for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: ShowPageAction(namespace='fallback-query.mark2.SearchingForAnswers.qml', page='file:///opt/mycroft-dinkum/skills/fallback-query.mark2/ui/SearchingForAnswers.qml', data=None)
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Exit handle utterance
Oct 27 20:27:15 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Completed action for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: SpeakAction(utterance='Just a second', dialog='just.one.moment', wait=False)
Oct 27 20:27:15 localhost.localdomain python[374]: DEBUG:audio:Speak for session '9023859f-2de5-41b4-bf84-7b1bfac96cef': Just a second (cache=False)
Oct 27 20:27:15 localhost.localdomain python[374]: DEBUG:audio:Segments: ['Just a second']
Oct 27 20:27:15 localhost.localdomain python[374]: DEBUG:mycroft.util.log:Started TTS session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:15 localhost.localdomain python[374]: DEBUG:audio:Submitted TTS chunk 1/1 for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: Just a second
Oct 27 20:27:15 localhost.localdomain python[374]: INFO:mycroft.util.log:Queued TTS chunk 1/1: file:///opt/mycroft/preloaded_cache/Mimic3/08c337e43e5de1dcf814cd674051b3f7.wav (session=9023859f-2de5-41b4-bf84-7b1bfac96cef): Just a second
Oct 27 20:27:15 localhost.localdomain python[374]: DEBUG:mycroft.util.log:Loading audio file: /opt/mycroft/preloaded_cache/Mimic3/08c337e43e5de1dcf814cd674051b3f7.wav
Oct 27 20:27:15 localhost.localdomain python[374]: INFO:mycroft.util.log:Ducked volume
Oct 27 20:27:15 localhost.localdomain python[374]: INFO:mycroft.util.log:Speaking TTS chunk 1/1 for 1.2770833333333333 sec from session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:16 localhost.localdomain python[374]: DEBUG:mycroft.util.log:TTS chunk finished playing for session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:16 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Audio finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:16 localhost.localdomain python[374]: INFO:mycroft.util.log:TTS session finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:16 localhost.localdomain python[377]: DEBUG:mycroft.util.log:TTS finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:16 localhost.localdomain python[374]: INFO:mycroft.util.log:Unducked volume
Oct 27 20:27:20 localhost.localdomain python[683]: DEBUG:mycroft.util.log:Removing event fallback-query.mark2:QuestionQueryTimeout
Oct 27 20:27:20 localhost.localdomain python[683]: INFO:fallback-query.mark2:Search timeout
Oct 27 20:27:20 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Requested session end: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:20 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Disabled idle timeout
Oct 27 20:27:20 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Completed action for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: SpeakAction(utterance='Beats me', dialog='noAnswer', wait=True)
Oct 27 20:27:20 localhost.localdomain python[374]: DEBUG:audio:Speak for session '9023859f-2de5-41b4-bf84-7b1bfac96cef': Beats me (cache=False)
Oct 27 20:27:20 localhost.localdomain python[374]: DEBUG:audio:Segments: ['Beats me']
Oct 27 20:27:20 localhost.localdomain python[374]: DEBUG:mycroft.util.log:Started TTS session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:20 localhost.localdomain python[374]: DEBUG:audio:Submitted TTS chunk 1/1 for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: Beats me
Oct 27 20:27:20 localhost.localdomain python[374]: INFO:mycroft.util.log:Queued TTS chunk 1/1: file:///opt/mycroft/preloaded_cache/Mimic3/5a1752f070528871fdc9809f0c3e301f.wav (session=9023859f-2de5-41b4-bf84-7b1bfac96cef): Beats me
Oct 27 20:27:20 localhost.localdomain python[374]: DEBUG:mycroft.util.log:Loading audio file: /opt/mycroft/preloaded_cache/Mimic3/5a1752f070528871fdc9809f0c3e301f.wav
Oct 27 20:27:20 localhost.localdomain python[374]: INFO:mycroft.util.log:Ducked volume
Oct 27 20:27:20 localhost.localdomain python[374]: INFO:mycroft.util.log:Speaking TTS chunk 1/1 for 0.8475208333333333 sec from session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:21 localhost.localdomain python[374]: DEBUG:mycroft.util.log:TTS chunk finished playing for session 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Audio finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:21 localhost.localdomain python[374]: INFO:mycroft.util.log:TTS session finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:TTS finished: 9023859f-2de5-41b4-bf84-7b1bfac96cef
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Disabled idle timeout
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Completed action for session 9023859f-2de5-41b4-bf84-7b1bfac96cef: ClearDisplayAction()
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Idle timeout set for 2 second(s)
Oct 27 20:27:21 localhost.localdomain python[374]: INFO:mycroft.util.log:Unducked volume
Oct 27 20:27:21 localhost.localdomain python[377]: DEBUG:mycroft.util.log:Cleaning up ended session: 9023859f-2de5-41b4-bf84-7b1bfac96cef

[LiberalArtist]

I can confirm that the issue was fixed by manually editing /home/mycroft/.config/mycroft/skills/news.mark2/settings.json to contain:

{"station": "NPR", "custom_url": ""}

[krisgesling]

Thanks for this Philip!

We've got a member of the team looking at it now and will let you know when we have more info.