Save state of hugveys to tmp to handle crashes

hugvey/central_command.py

@@ -128,6 +128,8 @@ class CentralCommand(object):
 #         status['counts'] = {t: len(a) for t, a in status['history'].items() if t != 'directions' }
         status['counts'] = {} if not hv.story else hv.story.getLogCounts()
         status['duration'] = 0 if not hv.story else hv.story.timer.getElapsed()
+        status['has_state'] = Story.hugveyHasSavedState(hv.id)
+        status['variables'] = {} if not isSelected or not hv.story else hv.story.variableValues
 
         return status
 
@@ -583,10 +585,20 @@ class HugveyState(object):
                     self.startMsgId = event['msg_id']
                     self.logger.debug(f"Restart from {self.startMsgId}")
                     self.restart()
+#                     Unfortunately setCurrentMessage() doesn't cut it, as the story
+#                        needs to be reloaded, this cannot be done with keeping the state either way
+#                     msg = self.story.get(event['msg_id'])
+#                     await self.story.setCurrentMessage(msg)
 
         self.eventQueue = None
 
     def setLanguage(self, language_code):
+        self.configureLanguage(language_code)
+
+        if self.isRunning.is_set():
+            self.restart()
+
+    def configureLanguage(self, language_code):
         if language_code not in self.command.languages:
             raise Exception("Invalid language {}".format(language_code))
 
@@ -596,11 +608,6 @@ class HugveyState(object):
         if self.google:
             self.google.setLanguage(language_code)
 
-        if self.isRunning.is_set():
-            self.restart()
-#         self.story.reset()
-#         self.story.setStoryData(self.command.languages[language_code])
-
     def pause(self):
         self.logger.info('Pause')
         if self.google:
@@ -611,7 +618,7 @@ class HugveyState(object):
         self.setStatus(self.STATE_PAUSE)
 
     def resume(self):
-        """ Start playing without reset"""
+        """Start playing without reset, also used to play from a saved state"""
         self.logger.info('Resume')
         if self.google:
             self.google.resume()
@@ -623,6 +630,8 @@ class HugveyState(object):
     def restart(self):
         """Start playing with reset"""
         self.logger.info('Restart')
+        if Story.hugveyHasSavedState(self.id):
+            Story.clearSavedState(self.id)
         if self.story:
             self.story.stop()
         self.resume()
@@ -702,15 +711,30 @@ class HugveyState(object):
             else:
                 # new story instance on each run
                 port = self.command.config['web']['port']
-                self.story = Story(self, port)
+                
-                startMsgId = self.startMsgId
+                if Story.hugveyHasSavedState(self.id):
-                self.startMsgId = None # use only once, reset before 'run'
+                    self.logger.info(f"Recovering from state :-)")
-                self.logger.warn(f"Starting from {startMsgId}")
+                    self.story = Story.loadStoryFromState(self)
+                    if self.story.language_code != self.language_code:
+                        self.logger.info("Changing language")
+                        self.configureLanguage(self.story.language_code)
+                else:
+                    self.story = Story(self, port)
+                    self.story.setStoryData(copy.deepcopy(self.command.languages[self.language_code]), self.language_code)
+                
+                
                 if not self.streamer:
                     await asyncio.sleep(1)
 
                 self.streamer.triggerStart()
-                self.story.setStoryData(copy.deepcopy(self.command.languages[self.language_code]))
+                
+                startMsgId = self.startMsgId
+                self.startMsgId = None # use only once, reset before 'run'    
+                if not startMsgId and self.story.currentMessage:
+                    startMsgId = self.story.currentMessage.id
+                
+                self.logger.info(f"Starting from {startMsgId}")
+                
                 self.setLightStatus(False)
                 await self.story.run(startMsgId)
 #             self.story = None

hugvey/story.py

@@ -16,6 +16,9 @@ import wave
 import sox
 from pythonosc import udp_client
 import random
+import pickle
+import os
+import traceback
 
 mainLogger = logging.getLogger("hugvey")
 logger = mainLogger.getChild("narrative")
@@ -39,6 +42,12 @@ class Utterance(object):
         return self.endTime is not None
     
     
+    def __getstate__(self):
+#         print(f'get utterance {self}')
+        state = self.__dict__.copy()
+        return state
+
+
 class Message(object):
     def __init__(self, id, text):
         self.id = id
@@ -60,6 +69,20 @@ class Message(object):
         self.uuid = None # Have a unique id each time the message is played back.
         self.color = None
     
+    def __getstate__(self):
+        # Copy the object's state from self.__dict__ which contains
+        # all our instance attributes. Always use the dict.copy()
+        # method to avoid modifying the original state.
+#         print(f'get msg {self.id}')
+        state = self.__dict__.copy()
+        # Remove the unpicklable entries.
+        del state['filenameFetchLock']
+        return state
+    
+    def __setstate__(self, state):
+        self.__dict__.update(state)
+        self.filenameFetchLock = asyncio.Lock()
+
     def setStory(self, story):
         self.story = story
         self.logger = story.logger.getChild("message")
@@ -183,12 +206,19 @@ class Message(object):
         return filename
 
 
+
 class Reply(object):
     def __init__(self, message: Message):
         self.forMessage = None
         self.utterances = []
         self.setForMessage(message)
     
+    
+    def __getstate__(self):
+#         print(f'get reply {self}')
+        state = self.__dict__.copy()
+        return state
+
     def setForMessage(self, message: Message):
         self.forMessage = message
         message.setReply(self)
@@ -265,6 +295,12 @@ class Condition(object):
         self.originalJsonString = None
         self.usedContainsDuration = None
     
+    
+    def __getstate__(self):
+#         print(f'get condition {self.id}')
+        state = self.__dict__.copy()
+        return state
+
     @classmethod
     def initFromJson(conditionClass, data, story):
         condition = conditionClass(data['@id'])
@@ -462,6 +498,12 @@ class Direction(object):
         self.conditionMet = None
         self.isDiversionReturn = False
     
+    
+    def __getstate__(self):
+#         print(f'get direction {self.id}')
+        state = self.__dict__.copy()
+        return state
+
     def addCondition(self, condition: Condition):
         self.conditions.append(condition)
 
@@ -524,6 +566,12 @@ class Diversion(object):
         if not self.method:
             raise Exception("No valid type given for diversion")
     
+    
+    def __getstate__(self):
+#         print(f'get diversion {self.id}')
+        state = self.__dict__.copy()
+        return state
+
     @classmethod
     def initFromJson(diversionClass, data, story):
         diversion = diversionClass(data['@id'], data['type'], data['params'])
@@ -945,6 +993,65 @@ class Stopwatch(object):
         if name in self.marks:
             self.marks.pop(name)
     
+    def __getstate__(self):
+#         print(f'get stopwatch')
+        state = self.__dict__.copy()
+        state['isRunning'] = self.isRunning.is_set()
+        return state
+    
+    def __setstate__(self, state):
+        self.__dict__.update(state)
+        
+        self.isRunning = asyncio.Event()
+        if 'isRunning' in state and state['isRunning']:
+            self.isRunning.set()
+        else:
+            self.isRunning.clear()
+        
+
+class StoryState(object):
+    """
+    Because Story not only contains state, but also logic/control variables, we need
+    a separate class to keep track of the state of things. This way, we can recreate
+    the exact state in which a story was before.
+    """
+    msgLog = []
+    currentMessage = None
+    currentDiversion = None
+    currentReply = None
+    allowReplyInterrupt = False
+    timer = Stopwatch()
+    isRunning = False
+
+    lastMsgTime = None
+    lastSpeechStartTime = None
+    lastSpeechEndTime = None
+    variableValues = {}  # captured variables from replies
+    finish_time = False
+
+    events = []  # queue of received events
+    commands = []  # queue of commands to send
+    log = []  # all nodes/elements that are triggered
+    msgLog = []
+
+    stats = {
+        'timeouts': 0,
+        'silentTimeouts': 0,
+        'consecutiveSilentTimeouts': 0,
+        'diversions': {
+            'no_response': 0,
+            'repeat': 0,
+            'reply_contains': 0,
+            'timeout': 0,
+            'timeout_total': 0,
+            'timeout_last': 0
+        }
+    }
+
+    def __init__(self):
+        pass
+#         
+
 class Story(object):
     """Story represents and manages a story/narrative flow"""
     # TODO should we separate 'narrative' (the graph) from the story (the
@@ -1017,11 +1124,12 @@ class Story(object):
     def hasVariableSet(self, name) -> bool:
         return name in self.variableValues and self.variableValues is not None
 
-    def setStoryData(self, story_data):
+    def setStoryData(self, story_data, language_code):
         """
         Parse self.data into a working story engine
         """
         self.data = story_data
+        self.language_code = language_code
 
         # keep to be able to reset it in the end
         currentId = self.currentMessage.id if self.currentMessage else None
@@ -1356,10 +1464,9 @@ class Story(object):
                 await self._processPendingEvents()
 
 #             Test stability of Central Command with deliberate crash
-#             if self.timer.getElapsed() > 5:
+#             if self.timer.getElapsed() > 10:
-#                 raise Exception('test')
+#                raise Exception("Test exception")
 
-                # The finish is not here anymore, but only on the playbackFinish event.
 
             directions = self.getCurrentDirections()
             await self._processDirections(directions)
@@ -1448,6 +1555,7 @@ class Story(object):
             logmsg += "\n- {0} -> {1} (when: {2}) ".format(direction.msgFrom.id, direction.msgTo.id, conditions)
 
         self.logger.log(LOG_BS,logmsg)
+        self.storeState()
 
     def getCurrentDirections(self):
         if self.currentMessage.id not in self.directionsPerMsg:
@@ -1566,5 +1674,75 @@ class Story(object):
             return None
 
         # TODO: should the direction have at least a timeout condition set, or not perse?
-
         return self.directionsPerMsg[msg.id][0]
+    
+    @classmethod
+    def getStateDir(self):
+        return "/tmp"
+#         day = time.strftime("%Y%m%d")
+#         t = time.strftime("%H:%M:%S")
+#         
+#         self.out_folder = os.path.join(self.main_folder, day, f"{self.hv_id}", t)
+#         if not os.path.exists(self.out_folder):
+#             self.logger.debug(f"Create directory {self.out_folder}")
+#             self.target_folder = os.makedirs(self.out_folder, exist_ok=True)
+    
+    @classmethod    
+    def getStateFilename(cls, hv_id):
+        return os.path.join(cls.getStateDir(), f"hugvey{hv_id}")
+    
+    def storeState(self):
+#        TODO: stop stopwatch
+        fn = self.getStateFilename(self.hugvey.id)
+        tmpfn = fn + '.tmp'
+        self.stateSave = time.time()
+        with open(tmpfn, 'wb') as fp:
+            pickle.dump(self, fp)
+            # write atomic to disk: flush, close, rename
+            fp.flush()
+            os.fsync(fp.fileno()) 
+            
+        os.rename(tmpfn, fn)
+        self.logger.debug(f"saved state to {fn}")
+    
+    def hasSavedState(self):
+        return self.hugveyHasSavedState(self.hugvey.id)
+    
+    @classmethod
+    def hugveyHasSavedState(cls, hv_id):
+        return os.path.exists(cls.getStateFilename(hv_id))
+    
+    @classmethod
+    def loadStoryFromState(cls, hugvey_state):
+#         restart stopwatch
+        with open(cls.getStateFilename(hugvey_state.id), 'rb') as fp:
+            story = pickle.load(fp)
+        
+        story.hugvey = hugvey_state
+        story.logger = mainLogger.getChild(f"{story.hugvey.id}").getChild("story")
+        return story
+        # TODO: take running state etc.
+    
+    @classmethod
+    def clearSavedState(cls, hv_id):
+        fn = cls.getStateFilename(hv_id)
+        if os.path.exists(fn):
+            os.unlink(fn)
+            mainLogger.info(f"Removed state: {fn}")
+#     
+    def __getstate__(self):
+        # Copy the object's state from self.__dict__ which contains
+        # all our instance attributes. Always use the dict.copy()
+        # method to avoid modifying the original state.
+        state = self.__dict__.copy()
+        
+        # Remove the unpicklable entries.
+        del state['hugvey']
+        del state['logger']
+#         del state['isRunning']
+         
+        return state
+ 
+    def __setstate__(self, state):
+        self.__dict__.update(state)
+

www/css/styles.css

@@ -350,3 +350,13 @@ body.showTimeline #toggleTimeline {
     color: orange; }
   #logbook .content .extra {
     color: #555; }
+
+#variables {
+  position: absolute;
+  bottom: 0;
+  left: 0;
+  color: white; }
+  #variables .name {
+    font-weight: bold; }
+    #variables .name::after {
+      content: " - "; }

www/index.html

@@ -68,6 +68,8 @@
 					<div class='btn' v-if="hv.status == 'running'" @click.stop="finish(hv)">Finish</div> <!-- to available state -->
 					<div class='btn' v-if="hv.status == 'running'" @click.stop="pause(hv)">Pause</div>
 					<div class='btn' v-if="hv.status == 'paused'" @click.stop="resume(hv)">Resume</div>
+					
+					<div class='btn' v-if="(hv.status == 'available' || hv.status == 'blocked') && hv.has_state" @click.stop="resume(hv)">Resume from save</div>
 				</div> 
 			</div>
 		</div>
@@ -96,6 +98,12 @@
 	            <g id='container'>
 	            </g>
 	        </svg>
+	        <ul v-for="hv in hugveys" v-if="hv.id == selectedId" id="variables">
+	        	<span v-if="!Object.keys(hv.variables).length">No variables set</span>
+		        <li v-for="(value, name) in hv.variables">
+		        	<span class='name'>{{name}}</span> <span class='value'>{{value}}</span>
+		        </li>
+	        </ul>
 		</div>
 	</div>
 	<script type='application/javascript' src="/js/hugvey_console.js"></script>

www/js/hugvey_console.js

@@ -146,6 +146,9 @@ class Panopticon {
 	                this.loadNarrative(hv.language);
 	            }
             }
+            
+//            let varEl = document.getElementById("variables");
+//            varEl.innerHTML = "";
         }
         
         if(this.hasGraph) {

www/scss/styles.scss

@@ -561,3 +561,16 @@ img.icon{
    		}
 	}
 }
+
+#variables{
+	position: absolute;
+    bottom: 0;
+    left: 0;
+    color: white;
+    .name{
+    	font-weight:bold;
+    	&::after{
+    		content:" - ";
+    	}
+    }
+}