MycroftAI / mycroft-timer

Mycroft AI official Timer Skill - set multiple named timers
https://mycroft.ai/skills
Apache License 2.0
7 stars 30 forks source link

fix failing tests for canceling an expired timer #99

Closed chrisveilleux closed 3 years ago

chrisveilleux commented 3 years ago

Description

Expiring timer tests were failing because of a new dialog that announced the expired timer.

Type of PR

If your PR fits more than one category, there is a high chance you should submit more than one PR. Please consider this carefully before opening the PR.

Testing

Run the VK tests for this skill. all should pass

Documentation

N/A

krisgesling commented 3 years ago

All the stop commands are failing on my machine for this, but it seems like it's caused by the check for stopping beeping.

This Then step checks to see if the paplay process still exists. But the process itself isn't terminating. So the audible beep stops, but the test fails.

I don't know how this previously passed on my machine unless something has changed. If I restart all services then paplay gets terminated. Speaking an utterance runs paplay for the duration of the dialog but once the timer beep starts that process continues to run even though it's not playing anything.

This seems like it could be a bug in core, but it's also a tenuous way for us to verify the beeping has stopped. I'm assuming we'll look at how the beep is handled during the Skills interaction sprint, but perhaps in the interim we need to trust if the Skills thinks the beep has stopped since it's the Skill calling the play_wav command at the moment.

krisgesling commented 3 years ago

Just for completeness - a little script to monitor the process in the same way as the test step:

import psutil
import time

while True:
    if "paplay" in [p.name() for p in psutil.process_iter()]:
        print("paplay running")
    else:
        print("STOPPED")
    time.sleep(1)
forslund commented 3 years ago

I think the issue here is that .wait() isn't called on the process so it will hang around defunct until cleaned.

L733 should be changed to something like

            play_proc = play_wav(str(self.sound_file_path))

And then last in the if-statement

            play_proc.wait()

The check is not ideal but not running wait is something we should definitely do.

We had some discussion about this in mycroft-core around a central service for playing sound-effects: https://github.com/MycroftAI/mycroft-core/issues/2965

chrisveilleux commented 3 years ago

@krisgesling These tests were failing on my Picroft until I made these changes, now they pass. The then condition in question was not altered as part of the timer skill refactor. Did you run these changes with the one-line fix to core VK tests I committed yesterday?

chrisveilleux commented 3 years ago

I agree that this check is not ideal. I would like to see an event emitted when playback has completed. Again, I did not change this code, nor did I change the code that calls the play_wav function. If @krisgesling is right about the process being active, these tests should have been failing for a long time. Not because of this PR

chrisveilleux commented 3 years ago

I just thought of a bigger problem. The beep is very short in duration. The code that plays it runs every two seconds as part of a repeating event. If the utterance fails to stop the expired timer, it is a race condition as to whether or not the beep is playing at the time. Even if the utterance was successful, there could be a race condition.

This would explain why these tests are failing sporadically in the CI process.

forslund commented 3 years ago

It's sort of weird that this hasn't been a problem all along yeah. But the original tests would be susceptible to false successes rather than false failures?

And I agree that this is separate to those issues and seems to be a good change.

chrisveilleux commented 3 years ago

Until the major refactor, this skill was only playing the beep once. It was one of the issues that was fixed. If the beep only occurred once, these tests would pass all the time.

forslund commented 3 years ago

Pretty sure the beep was playing once every 10 seconds? It may have worked due to the poll that was made before each restart of the playback...so the process remained defunct until the check if it had terminated (which was just before start of playback)...But the TODO makes me think I wasn't very confident in that :)

krisgesling commented 3 years ago

With the play process wait, these are now passing for me.

Merging.