Improve the speed of waiting for dialogs helper function

[chrisveilleux]

Description

The wait_for_dialogs step function in the Voight-Kampff test suite would loop until timeout regardless of whether or not a match was found. Also, there was no error condition if no match was found, so the step would always pass. This change adds logic to break out of the loop after a matching dialog is spoken and provides the status of the matching process. A new method was added to format a message detailing the error condition.

How to test

Tests that use this helper function should run faster.

Contributor license agreement signed?

CLA [Y]

[pep8speaks]

Hello @chrisveilleux! Thanks for updating this PR. We checked the lines you've touched for PEP 8 issues, and found:

There are currently no PEP 8 issues detected in this Pull Request. Cheers! 🍻

Comment last updated at 2021-08-04 22:06:56 UTC

[devops-mycroft]

Voight Kampff Integration Test Succeeded (Results)

[forslund]

I think it looks good in general, there is a pep-8 issue with a line that looks like it's a debug print, maybe that can just be removed?

Made a couple of comments but consider them suggestions and not requirements.

[forslund]

can bus.new_message_available.wait(0.5) be used to make it a bit more snappy?

[chrisveilleux]

In my testing, using the message_available event caused a very tight loop because there are so many message bus messages being emitted. Instead of looping ten times, as this code does, it looped hundreds of times. I would like to avoid these types of waits completely and just use message bus events with timeouts.

[forslund]

Not seeing the issue with the tight loop, this waits for messages as soon as messages arrive we want to evaluate them. But you are right in this case an event driven approach would be much tidier. Can we change the implementation to something similar to:

def wait_for_dialog_match(bus, dialogs, timeout=DEFAULT_TIMEOUT):
    """Match dialogs spoken to the specified list of expected dialogs.
    Only one of the dialogs in the provided list need to match for this
    check to be successful.
    Args:
        bus (InterceptAllBusClient): Bus instance to listen on
        dialogs (list): list of acceptable dialogs
        timeout (int): how long to wait for the message, defaults to timeout
                       provided by context or 10 seconds
    Returns:
        A boolean indicating if a match was found and the list of "speak"
        events found on the message bus during the matching process.
    """
    match_found = Event()
    speak_messages = list()

    def dialog_handler(message):
        nonlocal match_found
        nonlocal speak_messages
        dialog = message.data.get('meta', {}).get('dialog')
        speak_messages.append(message)
        if dialog in dialogs:
            wait_while_speaking()
            match_found.set()

    bus.on('speak', dialog_handler)
    # Check if the dialog has already been received
    historical_result = check_historical_messages()
    if historical_result:
        match_found.set()
    else:
        match_found.wait(timeout=timeout)
        bus.remove('speak', dialog_handler)
    return match_found.is_set(), speak_messages

Where historical messages would be just check the current stack of received messages for matches to handle the case where the desired 'speak' message arrives between the when and then steps.

[forslund]

Also the wait_for_dialogs() function is not a step-function, just a helper to do a wait. then_dialog() is the step function that checks the dialogs. This new function sort of duplicates that function.

[devops-mycroft]

Voight Kampff Integration Test Failed (Results).
Mycroft logs are also available: skills.log, audio.log, voice.log, bus.log, enclosure.log

[devops-mycroft]

Voight Kampff Integration Test Failed (Results).
Mycroft logs are also available: skills.log, audio.log, voice.log, bus.log, enclosure.log

[chrisveilleux]

Also the wait_for_dialogs() function is not a step-function, just a helper to do a wait. then_dialog() is the step function that checks the dialogs. This new function sort of duplicates that function.

Yes, wait_for_dialogs() also sort of duplicated then_wait(). I can't use then_dialog() in this case. The timer skill tests need the helper function. If more refactoring is needed for these functions to make more sense, I am open to that.

[forslund]

The change as it is good. Feel free to discard the suggestion.

[devops-mycroft]

Voight Kampff Integration Test Failed (Results).
Mycroft logs are also available: skills.log, audio.log, voice.log, bus.log, enclosure.log

[devops-mycroft]

Voight Kampff Integration Test Failed (Results).
Mycroft logs are also available: skills.log, audio.log, voice.log, bus.log, enclosure.log

[devops-mycroft]

Voight Kampff Integration Test Failed (Results).
Mycroft logs are also available: skills.log, audio.log, voice.log, bus.log, enclosure.log

[codecov-commenter]

Codecov Report

Merging #2946 (e6187fc) into dev (2deab67) will increase coverage by 0.20%.
The diff coverage is 89.18%.

❗ Current head e6187fc differs from pull request most recent head 8f41d17. Consider uploading reports for the commit 8f41d17 to get more accurate results

@@            Coverage Diff             @@
##              dev    #2946      +/-   ##
==========================================
+ Coverage   52.64%   52.85%   +0.20%     
==========================================
  Files         123      123              
  Lines       11021    11044      +23     
==========================================
+ Hits         5802     5837      +35     
+ Misses       5219     5207      -12     

Impacted Files	Coverage Δ
mycroft/skills/mycroft_skill/mycroft_skill.py	74.69% <ø> (ø)
mycroft/audio/audioservice.py	80.59% <40.00%> (-0.61%)	⬇️
mycroft/util/network_utils.py	94.44% <95.45%> (+40.59%)	⬆️
mycroft/skills/intent_services/adapt_service.py	80.71% <100.00%> (+0.13%)	⬆️
mycroft/tts/tts.py	79.60% <100.00%> (+0.13%)	⬆️
mycroft/util/format.py	100.00% <100.00%> (ø)
mycroft/util/parse.py	82.35% <100.00%> (+1.10%)	⬆️
mycroft/client/speech/listener.py	48.04% <0.00%> (-0.36%)	⬇️

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 2deab67...8f41d17. Read the comment docs.