diff --git a/.github/workflows/license_tests.yml b/.github/workflows/license_tests.yml index 3e61598..2a1167f 100644 --- a/.github/workflows/license_tests.yml +++ b/.github/workflows/license_tests.yml @@ -5,4 +5,6 @@ on: jobs: license_tests: - uses: neongeckocom/.github/.github/workflows/license_tests.yml@master \ No newline at end of file + uses: neongeckocom/.github/.github/workflows/license_tests.yml@master + with: + packages-exclude: '^(precise-runner|fann2|tqdm|bs4|ovos-phal-plugin|ovos-ocp|bitstruct|audioread).*' \ No newline at end of file diff --git a/CHANGELOG.md b/CHANGELOG.md index 357520a..b846ab2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,172 +1,52 @@ # Changelog -## [1.3.3a21](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a21) (2023-10-27) +## [1.4.1a6](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a6) (2023-12-13) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a20...1.3.3a21) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.1a5...1.4.1a6) **Merged pull requests:** -- Handle playback thread init bug affecting Docker instances [\#151](https://github.com/NeonGeckoCom/neon_audio/pull/151) ([NeonDaniel](https://github.com/NeonDaniel)) +- Update ovos-audio to remove excessive empty log [\#159](https://github.com/NeonGeckoCom/neon_audio/pull/159) ([NeonDaniel](https://github.com/NeonDaniel)) -## [1.3.3a20](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a20) (2023-10-27) +## [1.4.1a5](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a5) (2023-12-13) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a19...1.3.3a20) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.1a4...1.4.1a5) **Merged pull requests:** -- Downgrade OCP for ovos-core/NeonCore compat. [\#150](https://github.com/NeonGeckoCom/neon_audio/pull/150) ([NeonDaniel](https://github.com/NeonDaniel)) +- Update neon-utils dependency to stable release [\#158](https://github.com/NeonGeckoCom/neon_audio/pull/158) ([NeonDaniel](https://github.com/NeonDaniel)) -## [1.3.3a19](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a19) (2023-10-27) +## [1.4.1a4](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a4) (2023-11-21) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a18...1.3.3a19) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.1a3...1.4.1a4) **Merged pull requests:** -- Update OCP to latest alpha to resolve dependency error [\#149](https://github.com/NeonGeckoCom/neon_audio/pull/149) ([NeonDaniel](https://github.com/NeonDaniel)) +- Handle invalid timing metrics [\#157](https://github.com/NeonGeckoCom/neon_audio/pull/157) ([NeonDaniel](https://github.com/NeonDaniel)) -## [1.3.3a18](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a18) (2023-10-27) +## [1.4.1a3](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a3) (2023-11-17) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a17...1.3.3a18) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.1a2...1.4.1a3) **Merged pull requests:** -- Fix typo in thread state check [\#148](https://github.com/NeonGeckoCom/neon_audio/pull/148) ([NeonDaniel](https://github.com/NeonDaniel)) +- Send utterance metrics for PHAL plugin [\#156](https://github.com/NeonGeckoCom/neon_audio/pull/156) ([NeonDaniel](https://github.com/NeonDaniel)) -## [1.3.3a17](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a17) (2023-10-26) +## [1.4.1a2](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a2) (2023-11-15) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a16...1.3.3a17) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.1a1...1.4.1a2) **Merged pull requests:** -- Update dependencies to prep for stable release [\#147](https://github.com/NeonGeckoCom/neon_audio/pull/147) ([NeonDaniel](https://github.com/NeonDaniel)) +- Response timing and MQ fixes [\#155](https://github.com/NeonGeckoCom/neon_audio/pull/155) ([NeonDaniel](https://github.com/NeonDaniel)) -## [1.3.3a16](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a16) (2023-10-26) +## [1.4.1a1](https://github.com/NeonGeckoCom/neon_audio/tree/1.4.1a1) (2023-11-10) -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a15...1.3.3a16) +[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.4.0...1.4.1a1) **Merged pull requests:** -- Update dependencies to test for stable releases [\#146](https://github.com/NeonGeckoCom/neon_audio/pull/146) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a15](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a15) (2023-10-13) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a14...1.3.3a15) - -**Merged pull requests:** - -- Update dependencies for module compat. [\#145](https://github.com/NeonGeckoCom/neon_audio/pull/145) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a14](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a14) (2023-10-11) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a13...1.3.3a14) - -**Merged pull requests:** - -- ovos-audio compatibility updates [\#144](https://github.com/NeonGeckoCom/neon_audio/pull/144) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a13](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a13) (2023-10-10) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a12...1.3.3a13) - -**Merged pull requests:** - -- Update timing context for non-Neon skills [\#143](https://github.com/NeonGeckoCom/neon_audio/pull/143) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a12](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a12) (2023-10-10) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a11...1.3.3a12) - -**Merged pull requests:** - -- Pin upper limit to ovos-plugin-manager to work around breaking change [\#142](https://github.com/NeonGeckoCom/neon_audio/pull/142) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a11](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a11) (2023-10-04) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a10...1.3.3a11) - -**Merged pull requests:** - -- Timing metrics and ovos-audio compat [\#141](https://github.com/NeonGeckoCom/neon_audio/pull/141) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a10](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a10) (2023-08-16) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a9...1.3.3a10) - -**Merged pull requests:** - -- Improved language support and plugin compatibility [\#139](https://github.com/NeonGeckoCom/neon_audio/pull/139) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a9](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a9) (2023-07-26) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a8...1.3.3a9) - -**Merged pull requests:** - -- Update Dockerfile for Kubernetes [\#137](https://github.com/NeonGeckoCom/neon_audio/pull/137) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a8](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a8) (2023-07-18) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a7...1.3.3a8) - -**Merged pull requests:** - -- Mark old CLI entrypoint as deprecated [\#136](https://github.com/NeonGeckoCom/neon_audio/pull/136) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a7](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a7) (2023-07-12) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a6...1.3.3a7) - -**Merged pull requests:** - -- Pin ovos-audio dependency to resolve ident handling issue [\#135](https://github.com/NeonGeckoCom/neon_audio/pull/135) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a6](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a6) (2023-06-27) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a5...1.3.3a6) - -**Merged pull requests:** - -- Update Docker to use OVOS\_CONFIG envvars [\#134](https://github.com/NeonGeckoCom/neon_audio/pull/134) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a5](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a5) (2023-06-03) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a4...1.3.3a5) - -**Merged pull requests:** - -- Implement tests for CLI module [\#133](https://github.com/NeonGeckoCom/neon_audio/pull/133) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a4](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a4) (2023-05-25) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a3...1.3.3a4) - -**Merged pull requests:** - -- Fix missed refactoring in CLI entrypoints [\#132](https://github.com/NeonGeckoCom/neon_audio/pull/132) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a3](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a3) (2023-05-18) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a2...1.3.3a3) - -**Merged pull requests:** - -- Optimize module init [\#131](https://github.com/NeonGeckoCom/neon_audio/pull/131) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a2](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a2) (2023-05-17) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.3a1...1.3.3a2) - -**Merged pull requests:** - -- Add malloc debugging support [\#130](https://github.com/NeonGeckoCom/neon_audio/pull/130) ([NeonDaniel](https://github.com/NeonDaniel)) - -## [1.3.3a1](https://github.com/NeonGeckoCom/neon_audio/tree/1.3.3a1) (2023-05-17) - -[Full Changelog](https://github.com/NeonGeckoCom/neon_audio/compare/1.3.2...1.3.3a1) - -**Merged pull requests:** - -- Refactor for ovos-audio compat. [\#129](https://github.com/NeonGeckoCom/neon_audio/pull/129) ([NeonDaniel](https://github.com/NeonDaniel)) +- Add timing metrics for response to handler in MQ client [\#154](https://github.com/NeonGeckoCom/neon_audio/pull/154) ([NeonDaniel](https://github.com/NeonDaniel)) diff --git a/neon_audio/service.py b/neon_audio/service.py index 30bbf6f..833937e 100644 --- a/neon_audio/service.py +++ b/neon_audio/service.py @@ -62,8 +62,6 @@ def on_started(): class NeonPlaybackService(PlaybackService): - _stopwatch = Stopwatch("get_tts") - def __init__(self, ready_hook=on_ready, error_hook=on_error, stopping_hook=on_stopping, alive_hook=on_alive, started_hook=on_started, watchdog=lambda: None, @@ -134,6 +132,8 @@ def handle_speak(self, message): def handle_finished(_): audio_finished.set() + + # If we have an identifier, add a callback to wait for playback if speak_id: self.bus.once(speak_id, handle_finished) else: @@ -143,6 +143,7 @@ def handle_finished(_): if not audio_finished.wait(self._playback_timeout): LOG.warning(f"Playback not completed for {speak_id} within " f"{self._playback_timeout} seconds") + self.bus.remove(speak_id, handle_finished) elif speak_id: LOG.debug(f"Playback completed for: {speak_id}") @@ -157,22 +158,28 @@ def handle_get_tts(self, message): if not message.data.get("speaker"): LOG.info(f"No speaker data with request, " f"core defaults will be used.") + message.context.setdefault('timing', dict()) if text: + stopwatch = Stopwatch("api_get_tts", allow_reporting=True, + bus=self.bus) if not isinstance(text, str): + message.context['timing']['response_sent'] = time() self.bus.emit(message.reply( ident, data={"error": f"text is not a str: {text}"})) return try: - with self._stopwatch: + with stopwatch: responses = self.tts.get_multiple_tts(message) - message.context.setdefault('timing', dict()) - message.context['timing']['get_tts'] = self._stopwatch.time + message.context['timing']['get_tts'] = stopwatch.time LOG.debug(f"Emitting response: {responses}") + message.context['timing']['response_sent'] = time() self.bus.emit(message.reply(ident, data=responses)) except Exception as e: LOG.exception(e) + message.context['timing']['response_sent'] = time() self.bus.emit(message.reply(ident, data={"error": repr(e)})) else: + message.context['timing']['response_sent'] = time() self.bus.emit(message.reply(ident, data={"error": "No text provided."})) diff --git a/neon_audio/tts/neon.py b/neon_audio/tts/neon.py index fdd9407..798a88e 100644 --- a/neon_audio/tts/neon.py +++ b/neon_audio/tts/neon.py @@ -31,6 +31,8 @@ import os from os.path import dirname +from time import time + from json_database import JsonStorageXDG from ovos_bus_client.message import Message from ovos_plugin_manager.language import OVOSLangDetectionFactory,\ @@ -131,38 +133,68 @@ def get_requested_tts_languages(msg) -> list: return tts_reqs +def _sort_timing_metrics(timings: dict) -> dict: + """ + Sort combined timing context into timestamps and durations + """ + to_return = {"timestamps": {}, "durations": {}} + for key, val in timings.items(): + if not isinstance(val, float): + LOG.warning(f"Invalid timing metric: {key}={val}") + continue + if val > 10000.0: # Arbitrary value that is > longest duration + to_return["timestamps"][key] = val + else: + to_return["durations"][key] = val + LOG.debug(f"Parsed timing context: {to_return}") + return to_return + + class NeonPlaybackThread(PlaybackThread): def __init__(self, queue, bus=None): LOG.info("Initializing NeonPlaybackThread") PlaybackThread.__init__(self, queue, bus=bus) - def begin_audio(self, message=None): + def begin_audio(self, message: Message = None): # TODO: Mark signals for deprecation check_for_signal("isSpeaking") create_signal("isSpeaking") + assert message is not None + message.context.setdefault("timing", dict()) + message.context['timing']['audio_begin'] = time() PlaybackThread.begin_audio(self, message) def end_audio(self, listen, message=None): + assert message is not None PlaybackThread.end_audio(self, listen, message) + message.context['timing']['audio_end'] = time() # TODO: Mark signals for deprecation check_for_signal("isSpeaking") def _play(self): + # wav_file, vis, listen, ident, message ident = self._now_playing[3] - if not ident and len(self._now_playing) >= 5 and \ - isinstance(self._now_playing[4], Message): - LOG.debug("Handling new style playback") - ident = self._now_playing[4].context.get('ident') or \ - self._now_playing[4].context.get('session', - {}).get('session_id') + message = self._now_playing[4] + if not ident: + LOG.error("Missing ident. Try getting from Message context") + ident = message.context.get('ident') or \ + message.context.get('session', {}).get('session_id') + super()._play() + # Notify playback is finished LOG.info(f"Played {ident}") - self.bus.emit(Message(ident)) + self.bus.emit(message.forward(ident)) + + # Report timing metrics + message.context["timestamp"] = time() + self.bus.emit(message.forward("neon.metric", + {"name": "local_interaction", + **_sort_timing_metrics( + message.context['timing'])})) class WrappedTTS(TTS): def __new__(cls, base_engine, *args, **kwargs): - base_engine._stopwatch = Stopwatch("get_tts") base_engine.execute = cls.execute base_engine.get_multiple_tts = cls.get_multiple_tts # TODO: Below method is only to bridge compatibility @@ -202,6 +234,7 @@ def _init_neon(base_engine, *args, **kwargs): os.makedirs(cache_dir, exist_ok=True) base_engine.cache_dir = cache_dir base_engine.cached_translations = cached_translations + return base_engine def _init_playback(self, playback_thread: NeonPlaybackThread = None): @@ -258,6 +291,9 @@ def _get_tts(self, sentence: str, request: dict = None, **kwargs): def get_multiple_tts(self, message, **kwargs) -> dict: """ Get tts responses based on message context + @returns: dict of : {: , "genders" []}. + For remote requests, each `language` also contains: + "audio": {: } """ tts_requested = get_requested_tts_languages(message) LOG.debug(f"tts_requested={tts_requested}") @@ -315,35 +351,44 @@ def execute(self, sentence: str, ident: str = None, listen: bool = False, Arguments: sentence: (str) Sentence to be spoken - ident: (str) Id reference to current interaction + ident: (str) ID reference to current interaction listen: (bool) True if listen should be triggered at the end of the utterance. message: (Message) Message associated with request kwargs: (dict) optional keyword arguments to be passed to TTS engine get_tts method """ + stopwatch = Stopwatch("get_tts", True, self.bus) if message: # Make sure to set the speaking signal now if not message.context.get("klat_data"): create_signal("isSpeaking") # TODO: Should sentence and ident be added to message context? DM message.data["text"] = sentence - with self._stopwatch: + with stopwatch: responses = self.get_multiple_tts(message, **kwargs) message.context.setdefault('timing', dict()) - message.context['timing']['get_tts'] = self._stopwatch.time + message.context['timing']['get_tts'] = stopwatch.time LOG.debug(f"responses={responses}") - ident = message.data.get('speak_ident') or ident + ident = message.context.get('speak_ident') or ident # TODO dedicated klat handler/plugin if "klat_data" in message.context: LOG.info("Sending klat.response") + message.context['timing']['response_sent'] = time() self.bus.emit( message.forward("klat.response", {"responses": responses, "speaker": message.data.get("speaker")})) - self.bus.emit(Message(ident)) + # Emit `ident` message to indicate this transaction is complete + LOG.debug(f"Notify playback completed for {ident}") + self.bus.emit(message.forward(ident)) + message.context["timestamp"] = time() + self.bus.emit(message.forward("neon.metric", + {"name": "klat_interaction", + **_sort_timing_metrics( + message.context['timing'])})) else: # Local user has multiple configured languages (or genders) for r in responses.values(): diff --git a/requirements/requirements.txt b/requirements/requirements.txt index 196fa3a..c80c46f 100644 --- a/requirements/requirements.txt +++ b/requirements/requirements.txt @@ -1,9 +1,9 @@ -ovos-audio==0.0.2a27 +ovos-audio==0.0.2a28 ovos-utils~=0.0.35 ovos-config~=0.0.10 phoneme-guesser~=0.1 ovos-plugin-manager~=0.0.24 -neon-utils[network]~=1.6 +neon-utils[network]~=1.8 click~=8.0 click-default-group~=1.2 ovos-bus-client~=0.0.3 diff --git a/tests/api_method_tests.py b/tests/api_method_tests.py index 8665b4f..00bb52c 100644 --- a/tests/api_method_tests.py +++ b/tests/api_method_tests.py @@ -86,9 +86,13 @@ def test_get_tts_no_sentence(self): "ident": "123", "user": "TestRunner"} tts_resp = self.bus.wait_for_response(Message("neon.get_tts", {}, - context), + dict(context)), context["ident"]) - self.assertEqual(tts_resp.context, context) + for key in context: + if key != "timing": + self.assertEqual(context[key], tts_resp.context[key]) + self.assertIsInstance(tts_resp.context['timing']['response_sent'], + float, tts_resp.context['timing']) self.assertIsInstance(tts_resp.data.get("error"), str) self.assertEqual(tts_resp.data["error"], "No text provided.") @@ -97,9 +101,13 @@ def test_get_tts_invalid_type(self): "ident": "1234", "user": "TestRunner"} tts_resp = self.bus.wait_for_response(Message("neon.get_tts", - {"text": 123}, context), + {"text": 123}, + dict(context)), context["ident"], timeout=60) - self.assertEqual(tts_resp.context, context) + for key in context: + self.assertEqual(context[key], tts_resp.context[key]) + self.assertIsInstance(tts_resp.context['timing']['response_sent'], + float, tts_resp.context['timing']) self.assertTrue(tts_resp.data.get("error") .startswith("text is not a str:")) @@ -109,9 +117,13 @@ def test_get_tts_valid_default(self): "ident": str(time()), "user": "TestRunner"} tts_resp = self.bus.wait_for_response(Message("neon.get_tts", - {"text": text}, context), + {"text": text}, + dict(context)), context["ident"], timeout=60) - self.assertEqual(tts_resp.context, context) + for key in context: + self.assertEqual(context[key], tts_resp.context[key]) + self.assertIsInstance(tts_resp.context['timing']['response_sent'], + float, tts_resp.context['timing']) responses = tts_resp.data self.assertIsInstance(responses, dict) print(responses) diff --git a/version.py b/version.py index 8032306..aedba2f 100644 --- a/version.py +++ b/version.py @@ -26,4 +26,4 @@ # NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS # SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. -__version__ = "1.4.0" +__version__ = "1.5.0"