Refactor timing and add debug log

Prevent response error from affecting next input
NeonGeckoCom · Nov 14, 2023 · 0a1fdf9 · 0a1fdf9
1 parent bdf50b7
commit 0a1fdf9
Show file tree

Hide file tree

Showing 2 changed files with 10 additions and 5 deletions.
diff --git a/neon_iris/client.py b/neon_iris/client.py
@@ -143,12 +143,12 @@ def handle_neon_response(self, channel, method, _, body):
         resp_time = message.context['timing'].get('response_sent', recv_time)
         if recv_time != resp_time:
             transit_time = recv_time - resp_time
-            message.context['timing']['mq_from_core'] = transit_time
+            message.context['timing']['client_from_core'] = transit_time
             LOG.debug(f"Response MQ transit time={transit_time}")
         handling_time = recv_time - message.context['timing'].get('client_sent',
                                                                   recv_time)
         LOG.info(f"{message.msg_type} handled in {handling_time}")
-
+        LOG.debug(f"{pformat(message.context['timing'])}")
         if message.msg_type == "klat.response":
             LOG.info("Handling klat response event")
             self.handle_klat_response(message)
@@ -302,7 +302,6 @@ def _send_utterance(self, utterance: str, lang: str,
                       "data": message.data,
                       "context": merge_dict(message.context, context,
                                             new_only=True)}
-        serialized['context']['timing']['client_sent'] = time()
         self._send_serialized_message(serialized)
 
     def _send_audio(self, audio_file: str, lang: str,
@@ -320,11 +319,15 @@ def _send_audio(self, audio_file: str, lang: str,
                       "data": message.data,
                       "context": merge_dict(message.context, context,
                                             new_only=True)}
-        serialized['context']['timing']['client_sent'] = time()
         self._send_serialized_message(serialized)
 
     def _send_serialized_message(self, serialized: dict):
         try:
+            serialized['context']['timing']['client_sent'] = time()
+            if serialized['context']['timing'].get('gradio_sent'):
+                serialized['context']['timing']['iris_input_handling'] = \
+                    serialized['context']['timing']['client_sent'] - \
+                    serialized['context']['timing']['gradio_sent']
             self.connection.emit_mq_message(
                 self._connection.connection,
                 queue="neon_chat_api_request",

diff --git a/neon_iris/web_client.py b/neon_iris/web_client.py
@@ -148,7 +148,9 @@ def on_user_input(self, utterance: str, *args, **kwargs) -> str:
                             context={"gradio": {"session": gradio_id},
                                      "timing": {"wait_in_queue": in_queue,
                                                 "gradio_sent": time()}})
-        self._await_response.wait(30)
+        if not self._await_response.wait(30):
+            LOG.error("No response received after 30s")
+            self._await_response.set()
         self._response = self._response or "ERROR"
         LOG.info(f"Got response={self._response}")
         return self._response