Add prefetch of variables, and JSON saves are indented

hugvey/central_command.py

@@ -492,6 +492,6 @@ class HugveyState(object):
             
             self.logger.info("Start audio stream")
             await self.getStreamer().run()
-            self.logger.warn("stream has left the building")
+            self.logger.warn(f"stream has left the building from {self.ip}")
             # if we end up here, the streamer finished, probably meaning hte hugvey shutdown
             self.gone()

hugvey/client.py

@@ -9,6 +9,7 @@ import time
 import yaml
 import zmq
 from zmq.asyncio import Context
+import sys
 
 try:
 	import alsaaudio

hugvey/panopticon.py

@@ -158,7 +158,7 @@ def getUploadHandler(central_command):
             print(os.path.abspath(langFile))
             with open(langFile, 'w') as json_fp:
                 logger.info(f'Save story to {langFile} {json_fp}')
-                json.dump(storyData, json_fp)
+                json.dump(storyData, json_fp, indent=2)
                 
             # Reload language files for new instances
             central_command.loadLanguages()

hugvey/story.py

@@ -7,7 +7,6 @@ import urllib.parse
 from .communication import LOG_BS
 from tornado.httpclient import AsyncHTTPClient, HTTPRequest
 
-
 logger = logging.getLogger("narrative")
 
 class Utterance(object):
@@ -27,7 +26,6 @@ class Utterance(object):
         return self.endTime is not None
 
     
-    
 class Message(object):
     def __init__(self, id, text):
         self.id = id
@@ -36,11 +34,16 @@ class Message(object):
         self.reply = None
 #         self.replyTime = None
         self.audioFile= None
+        self.filenameFetchLock = asyncio.Lock()
         self.interruptCount = 0
         self.afterrunTime = 0. # the time after this message to allow for interrupts
         self.finishTime = None # message can be finished without finished utterance (with instant replycontains)
+        self.variableValues = {}
         self.parseForVariables()
     
+    def setStory(self, story):
+        self.story = story
+
     @classmethod
     def initFromJson(message, data, story):
         msg = message(data['@id'], data['text'])
@@ -48,6 +51,7 @@ class Message(object):
         msg.afterrunTime = data['afterrun'] if 'afterrun' in data else 0.
         if 'audio' in data:
             msg.audioFile = data['audio']['file']
+        msg.setStory(story)
         return msg
     
     def parseForVariables(self):
@@ -55,10 +59,40 @@ class Message(object):
         Find variables in text
         """
         self.variables = re.findall('\$(\w+)', self.text)
+        for var in self.variables:
+            self.variableValues[var] = None
     
     def hasVariables(self) -> bool:
         return len(self.variables) > 0
     
+    def setVariable(self, name, value):
+        if name not in self.variables:
+            logger.critical("Set nonexisting variable")
+            return
+        
+        if self.variableValues[name] == value:
+            return
+        
+        self.variableValues[name] = value
+        
+        logger.warn(f"Set variable, now fetch {name}")
+        if not None in self.variableValues.values():
+            logger.warn(f"now fetch indeed {name}")
+            asyncio.get_event_loop().create_task(self.getAudioFilePath())
+#             asyncio.get_event_loop().call_soon_threadsafe(self.getAudioFilePath)
+            logger.warn(f"started {name}")
+
+    def getText(self):
+        # sort reverse to avoid replacing the wrong variable
+        self.variables.sort(key=len, reverse=True)
+        text = self.text
+        logger.info(f"Getting text for {self.id}")
+        logger.debug(self.variables)
+        for var in self.variables:
+            logger.debug(f"try replacing ${var} with {self.variableValues[var]} in {text}")
+            text = text.replace('$'+var, self.variableValues[var])
+        return text
+    
     def setReply(self, reply):
         self.reply = reply
 
@@ -85,29 +119,34 @@ class Message(object):
         return {
             'id': self.id,
             'time': None if self.reply is None else [u.startTime for u in self.reply.utterances],
+            'text': self.getText(),
             'replyText': None if self.reply is None else [u.text for u in self.reply.utterances]
         }
         
-    async def getAudioFilePath(self,story):
+    async def getAudioFilePath(self):
         if self.audioFile is not None:
             return self.audioFile
         
-        client = AsyncHTTPClient()
+        logger.warn(f"Fetching audio for {self.getText()}")
-        queryString = urllib.parse.urlencode({
+        async with self.filenameFetchLock:
-            'text': self.text,
+            client = AsyncHTTPClient()
-            'filename': 1,
+            queryString = urllib.parse.urlencode({
-            'variable': 1 if self.hasVariables() else 0
+                'text': self.getText(),
-            })
+                'filename': 1,
-        request = HTTPRequest(
+                'variable': 1 if self.hasVariables() else 0
-            url = f"http://localhost:{story.panopticon_port}/voice?{queryString}",
+                })
-            method="GET"
+            request = HTTPRequest(
-            )
+                url = f"http://localhost:{self.story.panopticon_port}/voice?{queryString}",
-        logger.log(LOG_BS, request.url)
+                method="GET"
-        response = await client.fetch(request)
+                )
+            logger.log(LOG_BS, request.url)
+            response = await client.fetch(request)
+        
         if response.code != 200:
             logger.critical(f"Error when fetching filename: {response.code} for {queryString}")
             return None
         
+        logger.warn(f"Fetched audio for {self.getText()}")
         return response.body.decode().strip()
 
 
@@ -221,16 +260,19 @@ class Condition(object):
                 # Compile once, as we probably run it more than once
                 self.vars['regexCompiled'] = re.compile(self.vars['regex'])
             
-            t = story.currentReply.getText().lower()
+            t = r.getText().lower()
             logger.log(LOG_BS, 'attempt regex: {} on {}'.format(self.vars['regex'], t))
             result = self.vars['regexCompiled'].search(t)
             if result is None:
                 #if there is something to match, but not found, it's never ok
                 return False
             logger.debug('Got match on {}'.format(self.vars['regex']))
-            results = result.groupdict()
+            
-            for captureGroup in results:
+            if 'instantMatch' in self.vars and self.vars['instantMatch'] or not r.isSpeaking():
-                story.variableValues[captureGroup] = results[captureGroup]
+                # try to avoid setting variables for intermediate strings
+                results = result.groupdict()
+                for captureGroup in results:
+                    story.setVariableValue(captureGroup, results[captureGroup])
             
             if 'instantMatch' in self.vars and self.vars['instantMatch']:
                 logger.info(f"Instant match on {self.vars['regex']}, {self.vars}")
@@ -238,13 +280,14 @@ class Condition(object):
             # TODO: implement 'instant match' -> don't wait for isFinished()
         
         if r.isSpeaking():
-            logger.log(LOG_BS, "is speaking")
+            logger.log(LOG_BS, f"is speaking: {r.getLastUtterance().text} - {r.getLastUtterance().startTime}")
             return False
         
 #         print(self.vars)
         # either there's a match, or nothing to match at all
         if 'delays' in self.vars:
             if story.lastMsgFinishTime is None:
+                logger.debug("not finished playback yet")
                 return False
             # time between finishing playback and ending of speaking:
             replyDuration = r.getLastUtterance().endTime - story.lastMsgFinishTime
@@ -257,6 +300,7 @@ class Condition(object):
                         return True
                     break # don't check other delays
             # wait for delay to match
+            logger.debug("Wait for it...")
             return False
         
         # There is a match and no delay say, person finished speaking. Go ahead sir!
@@ -428,6 +472,14 @@ class Story(object):
         else:
             self.variables[variableName].append(message)
     
+    def setVariableValue(self, name, value):
+        if name not in self.variables:
+            logger.warn(f"Set variable that is not needed in the story: {name}")
+        self.variableValues[name] = value
+        
+        for message in self.variables[name]:
+            message.setVariable(name, value)
+
     def setStoryData(self, story_data):
         """
         Parse self.data into a working story engine
@@ -461,6 +513,17 @@ class Story(object):
                 logger.warn(
                     "Could not reinstatiate current message. Starting over")
         
+        # Register variables
+        for msg in self.getMessages():
+            print(msg.id, msg.hasVariables())
+            if not msg.hasVariables():
+                continue
+            
+            for var in msg.variables:
+                self.registerVariable(var, msg)
+                
+        logger.info(f'has variables: {self.variables}')
+
     def reset(self):
         self.timer.reset()
 #         self.startTime = time.time()
@@ -505,8 +568,9 @@ class Story(object):
         if id in self.elements:
             return self.elements[id]
         return None
+    
     def getMessages(self):
-        return [el for el in self.elements if type(el) == Message]
+        return [el for el in self.elements.values() if type(el) == Message]
         
     def stop(self):
         logger.info("Stop Story")
@@ -642,7 +706,7 @@ class Story(object):
         # TODO: preload file paths if no variables are set, or once these are loaded
         self.hugvey.sendCommand({
             'action': 'play',
-            'file': await message.getAudioFilePath(self),
+            'file': await message.getAudioFilePath(),
             'id': message.id,
         })