Different skill getting called while my skill is executing

Hey all,

I’ve been working on this Nextcloud Calendar skill for a bit and have recently ran into an issue where in the middle of this skill being used, other skills are being called, and it is conflicting with the desired flow of the calendar skill. I’ve copied the Mycroft messagebus log output at the bottom of this post.

What seems to be happening is:

  1. I say “add an event to my calendar tomorrow at 11:15am”.
  2. Mycroft asks me how long the event will last.
  3. I say “30 minutes”
  4. Mycroft asks me what the event should be called.
  5. I say the event name. (in this case “Julia nail trim”)
  6. Mycroft repeats the details to confirm ("Confirm the addition of Julia nail trim on…)
  7. Immediately after mycroft finishes speaking the confirmation, “An error occurred while processing a request in Timer Skill”.
  8. I say “yes” to confirm step 6.
  9. The Question Answer Skill is somehow triggered, the the query times out. My event is not added to the calendar.

This is not the only example of this happening, but it is consistent with other examples. I thought maybe the “30 minutes” or “half an hour” utterance from (3) could be triggering the Timer skill. But when I say “Hey Mycroft… thirty minutes”, Mycroft tells me what the time will be 30 minutes from now; does not seem to trigger the timer skill.

Messagebus log output:
Establishing Mycroft Messagebus connection…
Connected to Messagebus!
17:24:40.803 | INFO | 711 | mycroft.session:get:74 | New Session Start: 358e9b2b-669c-4d8a-950d-8da632f51532
17:24:40.808 | INFO | 711 | main:handle_wakeword:67 | Wakeword Detected: hey mycroft
Playing WAVE ‘/home/pi/mycroft-core/mycroft/res/snd/start_listening.wav’ : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
17:24:41.277 | INFO | 711 | main:handle_record_begin:37 | Begin Recording…
17:24:45.116 | INFO | 711 | main:handle_record_end:45 | End Recording…
17:24:46.156 | INFO | 711 | main:handle_utterance:72 | Utterance: [‘add an event to my calendar tomorrow at 11:15 a.m.’]
17:24:46.681 | INFO | 705 | NextcloudCalendarSkill | using owner: my
Playing WAVE ‘/home/pi/mycroft-core/mycroft/res/snd/start_listening.wav’ : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
17:24:49.527 | INFO | 711 | main:handle_record_begin:37 | Begin Recording…
17:24:51.450 | INFO | 711 | main:handle_record_end:45 | End Recording…
17:24:52.904 | INFO | 711 | main:handle_utterance:72 | Utterance: [‘30 minutes’]
Playing WAVE ‘/home/pi/mycroft-core/mycroft/res/snd/start_listening.wav’ : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
17:24:56.212 | INFO | 711 | main:handle_record_begin:37 | Begin Recording…
17:24:58.767 | INFO | 711 | main:handle_record_end:45 | End Recording…
17:25:00.385 | INFO | 711 | main:handle_utterance:72 | Utterance: [‘julia nail trim’]
~~~~ | 705 | mycroft.skills.mycroft_skill.mycroft_skill:on_error:835 | An error occurred while processing a request in Timer Skill
Traceback (most recent call last):
File “/home/pi/mycroft-core/mycroft/skills/mycroft_skill/event_container.py”, line 66, in wrapper
handler(message)
File “/opt/mycroft/skills/mycroft-timer.mycroftai/init.py”, line 130, in handle_listener_ended
self.is_not_listening)
File “/home/pi/mycroft-core/mycroft/messagebus/client/client.py”, line 213, in remove
self.emitter.remove_listener(event_name, func)
File “/home/pi/mycroft-core/.venv/lib/python3.7/site-packages/pyee/_base.py”, line 136, in remove_listener
self._events[event].pop(f)
KeyError: <bound method TimerSkill.is_not_listening of <mycroft-timer_mycroftai.TimerSkill object at 0x831b6570>>
Playing WAVE ‘/home/pi/mycroft-core/mycroft/res/snd/start_listening.wav’ : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
17:25:40.226 | INFO | 711 | main:handle_record_begin:37 | Begin Recording…
17:25:44.478 | INFO | 711 | main:handle_record_end:45 | End Recording…
17:25:45.491 | INFO | 711 | main:handle_utterance:72 | Utterance: [‘yes’]
17:25:45.917 | INFO | 705 | QuestionsAnswersSkill | Searching for yes
Removing event fallback-query.mycroftai:QuestionQueryTimeout
Removing event fallback-query.mycroftai:QuestionQueryTimeout
Removing event fallback-query.mycroftai:QuestionQueryTimeout
Removing event fallback-query.mycroftai:QuestionQueryTimeout
Removing event fallback-query.mycroftai:QuestionQueryTimeout
17:25:46.063 | INFO | 705 | QuestionsAnswersSkill | Timeout occured check responses

Bumping this, as it’s been a while and I still have not yet found a solution. Anyone have any tips?

So I did a bit of testing on mycroft without installing your skill and discovered a couple things that might help you out. But ultimately I think your skill is not being called at all and a fallback skill is taking the commands. The issue is the responses of the fallback skill are also not correct so, I am going to reach out to @gez-mycroft to see if he knows who to ask about the fallback skill that is causing some grief.

  1. The fallback question and answer skill gets invoked on just about anything you throw at it and this is definitely causing some of your issues based on the logs. I passed mycroft each of the utterances that you have in your log above and each time the question and answer skill replied (incorrectly i think).

Based on your utterances…
if you ask mycroft add an event to my calendar tomorrow at 11:15 a.m.
mycroft will respond with How long of a timer?

if you ask mycroft at any time 30 minutes
mycroft will respond with I'm starting a timer for thirty minutes

if you ask mycroft julia nail trim
mycroft will respond with How long of a timer?
This is also a very odd response.

If I get some time in the next few days I will have a bit of a look into your skill to see if it is obvious why it is not getting invoked as you expect. The best advice I could give you is to add lots of logging initially then so you can trace it through to find out where the issues are.

Good Luck!

@pcwii thanks for the response! I’m pretty confident that the skill is being called given that it makes it to the point where it asks for confirmation before adding the event to the calendar, but you’re right, at some point it must fail out of my skill. Although not completely. This isn’t shown in the logs I pasted above, but if in step 8, I do not say “yes” or “no” and stay silent, Mycroft does repeat the confirmation dialog. So it seems like that functionality of my skill is persisting, despite the fact that an “error occurred while processing a request in Timer Skill”. Hope that additional bit of info is helpful.

Repeating the request for confirmation is a single function. iirc it’s a while loop. I know it breaks after a while, but I forget when.

Ah, there is an issue that is getting raised by the Timer Skill however it doesn’t seem to be triggering any of the Timer intents.

Basically, there are event handlers to check when Mycroft is listening so the timer beep doesn’t get played while the listener is activated. It seems that it was trying to remove that event when perhaps it had already been cleared:

~~~~ | 705 | mycroft.skills.mycroft_skill.mycroft_skill:on_error:835 | An error occurred while processing a request in Timer Skill
Traceback (most recent call last):
File “/home/pi/mycroft-core/mycroft/skills/mycroft_skill/event_container.py”, line 66, in wrapper
handler(message)
File “/opt/mycroft/skills/mycroft-timer.mycroftai/init.py”, line 130, in handle_listener_ended
self.is_not_listening)
File “/home/pi/mycroft-core/mycroft/messagebus/client/client.py”, line 213, in remove
self.emitter.remove_listener(event_name, func)
File “/home/pi/mycroft-core/.venv/lib/python3.7/site-packages/pyee/_base.py”, line 136, in remove_listener
self._events[event].pop(f)
KeyError: <bound method TimerSkill.is_not_listening of <mycroft-timer_mycroftai.TimerSkill object at 0x831b6570>>

I’ve seen this before, or at least something similar, can I check what version of mycroft-core you are running?
Can you also check which version of Pyee you have using this command?

mycroft-pip list | grep pyee

pyee v8.1.0
mycroft core 20.08.1