Wait a bit more before starting to complain

[saartuer.git] / statemachine.py

diff --git a/statemachine.py b/statemachine.py
index fe926823d140c9e152ccc7dd424c95ed3fcc4c12..0fa485abcd7d25a146d578357a3803aa8f1905b6 100644 (file)
--- a/statemachine.py
+++ b/statemachine.py
@@ -1,6 +1,6 @@
-from libtuer import ThreadFunction, logger, fire_and_forget
+from libtuer import ThreadFunction, logger, fire_and_forget, fire_and_forget_cmd

 from actor import Actor
 from actor import Actor

-import os, random
+import os, random, time, threading

 
 # logger.{debug,info,warning,error,critical}
 
 
 # logger.{debug,info,warning,error,critical}
 


@@ -11,187 +11,329 @@ def play_sound (what):
                logger.error("StateMachine: Unable to list sound files in %s" % (SOUNDS_DIRECTORY+what))
                return
        soundfile = SOUNDS_DIRECTORY + what + '/' + random.choice(soundfiles)
                logger.error("StateMachine: Unable to list sound files in %s" % (SOUNDS_DIRECTORY+what))
                return
        soundfile = SOUNDS_DIRECTORY + what + '/' + random.choice(soundfiles)

-       fire_and_forget ([SOUNDS_PLAYER,soundfile], logger.error, "StateMachine: ")
+       fire_and_forget_cmd ([SOUNDS_PLAYER,soundfile], "StateMachine: ")

 
 

+# convert an absolute nervlist to a relative one
+def nervlist_abs2rel(nervlist_abs):
+       nervlist_rel = []
+       last_t = 0
+       for (t, f) in nervlist_abs:
+               assert t >= last_t
+               nervlist_rel.append((t-last_t, f))
+               last_t = t
+       return nervlist_rel

 
 

-# StateOpening constants
-OPEN_REPEAT_TIMEOUT = 8
+# StateAuf constants
+HELLO_PROBABILITY = 0.2
+
+# StateUnlocking constants
+OPEN_REPEAT_TIMEOUT = 7

 OPEN_REPEAT_NUMBER = 3
 
 OPEN_REPEAT_NUMBER = 3
 

+# StateLocking constants
+CLOSE_REPEAT_TIMEOUT = 7
+CLOSE_REPEAT_NUMBER = 3
+
+# StateFallback constants
+FALLBACK_LEAVE_DELAY_LOCK = 5 # seconds
+

 # StateAboutToOpen constants
 # StateAboutToOpen constants

-ABOUTOPEN_NERVLIST = [(5, lambda : play_sound("flipswitch")), (10, lambda:play_sound("flipswitch")), (10, lambda:Logger.warning("Space open but switch not flipped for 10 seconds")),\
-       (20, lambda:play_sound("flipswitch")), (30, lambda:play_sound("flipswitch")), (30, lambda:Logger.error("Space open but switch not flipped for 30 seconds")),\
-       (40, lambda:play_sound("flipswitch")), (50, lambda:play_sound("flipswitch")), (56, lambda:play_sound("flipswitch")), (60, lambda:Logger.critical("Space open but switch not flipped for 60 seconds"))]
+SWITCH_PRAISE_PROBABILITY = 0.5
+ABOUTOPEN_NERVLIST = nervlist_abs2rel([(10, lambda:play_sound("flipswitch")),\
+       (20, lambda:play_sound("flipswitch")), (30, lambda:play_sound("flipswitch")), (30, lambda:logger.error("Space open but switch not flipped for 30 seconds")),\
+       (40, lambda:play_sound("flipswitch")), (50, lambda:play_sound("flipswitch")), (60, lambda:play_sound("mail_sent")),
+       (60, lambda:logger.critical("Space open but switch not flipped for 60 seconds")), (120, lambda:play_sound("mail_sent")),
+       (10*60, lambda:logger.critical("Space open but switch not flipped for 10 minutes")),
+       (60*60, lambda:logger.critical("Space open but switch not flipped for one hour"))])

 
 

-# StateAuf constants
-#  time that must pass between two bell_ringing events to buzz the door again (seconds)
-AUF_BELLBUZZ_REPEAT_TIME = 2
+# Timeout we wait after the switch was switched to "Closed", until we assume nobody will open the door and we just lock it
+# ALso the time we wait after the door was opend, till we assume something went wrong and start nerving
+LEAVE_TIMEOUT = 20

 
 # play_sound constants
 SOUNDS_DIRECTORY = "/opt/tuer/sounds/"
 SOUNDS_PLAYER = "/usr/bin/mplayer"
 
 
 
 # play_sound constants
 SOUNDS_DIRECTORY = "/opt/tuer/sounds/"
 SOUNDS_PLAYER = "/usr/bin/mplayer"
 
 

+class Nerver():
+       # A little utility class used to run the nervlists. A nervlist is a list of (n, f) tuples where f() is run after n seconds.
+       # If f returns something, that's also returned by nerv.
+       def __init__(self, nervlist):
+               self.nervlist = list(nervlist)
+               self.last_event_time = time.time()
+       
+       def nerv(self):
+               if len(self.nervlist):
+                       (wait_time, f) = self.nervlist[0]
+                       now = time.time()
+                       time_gone = now-self.last_event_time
+                       # check if the first element is to be triggered
+                       if time_gone >= wait_time:
+                               self.nervlist = self.nervlist[1:] # "pop" the first element, but do not modify original list
+                               self.last_event_time = now
+                               return f()
+
+

 class StateMachine():
        # commands you can send
        CMD_PINS = 0
        CMD_BUZZ = 1
 class StateMachine():
        # commands you can send
        CMD_PINS = 0
        CMD_BUZZ = 1

-       CMD_OPEN = 2
+       CMD_UNLOCK = 2

        CMD_WAKEUP = 3
        CMD_LAST = 4
        
        class State():
        CMD_WAKEUP = 3
        CMD_LAST = 4
        
        class State():

-               def __init__(self, state_machine):
+               def __init__(self, state_machine, nervlist = None):

                        self.state_machine = state_machine
                        self.state_machine = state_machine

-                       self.time_entered = time.time()
-                       self.theDict = None
-                       self.last_wakeup = self.time_entered
+                       self._nerver = None if nervlist is None else Nerver(nervlist)

                def handle_pins_event(self):
                        pass # one needn't implement this
                def handle_buzz_event(self,arg): # this shouldn't be overwritten
                def handle_pins_event(self):
                        pass # one needn't implement this
                def handle_buzz_event(self,arg): # this shouldn't be overwritten

-                       self.actor.act(Actor.CMD_BUZZ)
+                       self.actor().act(Actor.CMD_BUZZ)

                        arg("200 okay: buzz executed")
                        arg("200 okay: buzz executed")

-               def handle_open_event(self,arg):
+               def handle_cmd_unlock_event(self,arg):

                        if arg is not None:
                        if arg is not None:

-                               arg("412 Precondition Failed: The current state (%s) cannot handle the OPEN event" % self.__class__.__name__)
+                               arg("412 Precondition Failed: The current state (%s) cannot handle the UNLOCK command. Try again later." % self.__class__.__name__)

                def handle_wakeup_event(self):
                def handle_wakeup_event(self):

-                       self.last_wakeup = time.time()
+                       if self._nerver is not None:
+                               return self._nerver.nerv()
+               def on_leave(self):
+                       pass

                def pins(self):
                        return self.state_machine.pins
                def pins(self):
                        return self.state_machine.pins

+               def old_pins(self):
+                       return self.state_machine.old_pins

                def actor(self):
                        return self.state_machine.actor
                def actor(self):
                        return self.state_machine.actor

+               def api(self):
+                       return self.state_machine.api

                def handle_event(self,ev,arg): # don't override
                def handle_event(self,ev,arg): # don't override

-                       if arg is CMD_PINS:
-                               self.handle_pins_event()
-                       elif arg is CMD_BUZZ:
-                               self.handle_buzz_event(arg)
-                       elif arg is CMD_OPEN:
-                               self.handle_open_event(arg)
-                       elif arg is CMD_WAKEUP:
-                               self.handle_wakeup_event()
+                       if ev == StateMachine.CMD_PINS:
+                               return self.handle_pins_event()
+                       elif ev == StateMachine.CMD_BUZZ:
+                               return self.handle_buzz_event(arg)
+                       elif ev == StateMachine.CMD_UNLOCK:
+                               return self.handle_cmd_unlock_event(arg)
+                       elif ev == StateMachine.CMD_WAKEUP:
+                               return self.handle_wakeup_event()

                        else:
                                raise Exception("Unknown command number: %d" % ev)
        
                        else:
                                raise Exception("Unknown command number: %d" % ev)
        

-       class StateStart(State):
-               def __init__(self, sm):
-                       State.__init__(self,sm)
+       class AbstractNonStartState(State):

                def handle_pins_event(self):
                def handle_pins_event(self):

-                       thepins = self.pins()
-                       for pin in thepins:
-                               if pin is None:
-                                       return None
-                       if thepins.door_locked:
-                               return StateZu
+                       if self.pins().door_locked != (not self.pins().space_active):
+                               self.actor().act(Actor.CMD_RED_ON)

                        else:
                        else:

-                               return StateAuf
-
-       class StateZu(State):
-               def __init__(self,sm):
-                       State.__init__(self,sm)
+                               self.actor().act(Actor.CMD_RED_OFF)
+                       return super().handle_pins_event()
+       
+       class AbstractLockedState(AbstractNonStartState):
+               '''A state with invariant "The space is locked", switching to StateAboutToOpen when the space becomes unlocked'''
+               def __init__(self, sm, nervlist = None):
+                       super().__init__(sm, nervlist)
+                       self.actor().act(Actor.CMD_GREEN_OFF)
+               def handle_pins_event(self):
+                       if not self.pins().door_locked:
+                               logger.info("Door unlocked, space is about to open")
+                               return StateMachine.StateAboutToOpen(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class AbstractUnlockedState(AbstractNonStartState):
+               '''A state with invariant "The space is unlocked", switching to StateZu when the space becomes locked'''
+               def __init__(self, sm, nervlist = None):
+                       super().__init__(sm, nervlist)
+                       self.actor().act(Actor.CMD_GREEN_ON)
+               def handle_pins_event(self):
+                       if self.pins().door_locked:
+                               logger.info("Door locked, closing space")
+                               if self.pins().space_active:
+                                       logger.warning("StateMachine: door manually locked, but space switch is still on - going to StateZu")
+                                       play_sound("manual_lock")
+                               return StateMachine.StateZu(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class StateStart(State):
+               def __init__(self, sm, nervlist = None, fallback=False):
+                       super().__init__(sm, nervlist)
+                       self.fallback = fallback

                def handle_pins_event(self):
                        pins = self.pins()
                def handle_pins_event(self):
                        pins = self.pins()

-                       if not pins.door_locked:
-                               return StateAboutToOpen(self.state_machine)
-               def handle_open_event(self,callback):
-                       return StateOpening(callback,self.state_machine)
-       
-       class StateOpening(State):
-               def __init__(self,callback,sm):
-                       State.__init__(self,sm)
-                       self.callbacks=[callback]
-                       # FIXME: can we send "202 processing: Trying to open the door" here? Are the callbacks multi-use?
-                       self.tries = 0
-                       self.actor().act(Actor.CMD_OPEN)
-               def notify(self, did_it_work):
-                       s = "200 okay: door open" if did_it_work else ("500 internal server error: Couldn't open door with %d tries à %f seconds" % (OPEN_REPEAT_NUMBER,OPEN_REPEAT_TIMEOUT))
-                       for cb in self.callbacks:
-                               if cb is not None:
-                                       cb(s)
+                       if not (pins.door_locked is None or pins.door_closed is None or pins.space_active is None or pins.bell_ringing is None):
+                               if self.fallback:
+                                       logger.info("Going to StateFallback because running in fallback mode")
+                                       return StateMachine.StateFallback(self.state_machine)
+                               if pins.door_locked:
+                                       logger.info("All sensors got a value, switching to a proper state: Space is closed")
+                                       return StateMachine.StateZu(self.state_machine)
+                               else:
+                                       logger.info("All sensors got a value, switching to a proper state: Space is (about to) open")
+                                       return StateMachine.StateAboutToOpen(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class StateFallback(State):
+               def __init__(self, sm, nervlist = None):
+                       super().__init__(sm, nervlist)
+                       self._red_state = False

                def handle_pins_event(self):
                        pins = self.pins()
                def handle_pins_event(self):
                        pins = self.pins()

-                       if not pins.door_locked:
-                               self.notify(True)
-                               return StateAboutToOpen(self.state_machine)
-               def handle_open_event(self,callback):
-                       # FIXME: 202 notification also here if possible
-                       self.callbacks.append(callback)
+                       # buzz if open and bell rang
+                       if pins.space_active and pins.bell_ringing and not self.old_pins().bell_ringing:
+                               logger.info("StateFallback: Space switch on and door bell rung => buzzing")
+                               self.actor().act(Actor.CMD_BUZZ)
+                       # set green LED according to space switch
+                       if pins.space_active:
+                               self.actor().act(Actor.CMD_GREEN_ON)
+                       else:
+                               self.actor().act(Actor.CMD_GREEN_OFF)
+                       # primitive leaving procedure if space switch turned off
+                       if not pins.space_active and self.old_pins().space_active:
+                               def _close_after_time():
+                                       time.sleep(FALLBACK_LEAVE_DELAY_LOCK)
+                                       self.actor().act(Actor.CMD_LOCK)
+                               fire_and_forget(_close_after_time)
+                       # not calling superclass because we want to stay in fallback mode

                def handle_wakeup_event(self):
                def handle_wakeup_event(self):

-                       over = time.time() - self.time_entered
-                       nexttry = (self.tries+1) * OPEN_REPEAT_TIMEOUT
-                       if over > nexttry:
-                               if self.tries < OPEN_REPEAT_NUMBER:
-                                       self.actor().act(Actor.CMD_OPEN)
-                                       self.tries += 1
-                               else:
-                                       logger.critical("Couldn't open door after %d tries. Going back to StateZu." % OPEN_REPEAT_NUMBER)
-                                       self.notify(False)
-                                       return StateZu(self.state_machine)
-       
-       class AbstractStateWhereOpeningIsRedundant(State):
-               def __init__ (self,sm):
-                       State.__init__(sm):
-               def handle_open_event(self, callback):
+                       # blink red LED
+                       if self._red_state:
+                               self.actor().act(Actor.CMD_RED_OFF)
+                               self._red_state = False
+                       else:
+                               self.actor().act(Actor.CMD_RED_ON)
+                               self._red_state = True
+               def handle_cmd_unlock_event(self,arg):
+                       if arg is not None:
+                               arg("298 Fallback Okay: Trying to unlock the door. The System is in fallback mode, success information is not available.")
+                       self.actor().act(Actor.CMD_UNLOCK)
+       
+       class StateZu(AbstractLockedState):
+               def handle_cmd_unlock_event(self,callback):
+                       return StateMachine.StateUnlocking(self.state_machine, callback)
+               def handle_pins_event(self):
+                       if not self.old_pins().space_active and self.pins().space_active: # first thing to check: edge detection
+                               logger.info("Space toggled to active while it was closed - unlocking the door")
+                               return StateMachine.StateUnlocking(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class StateUnlocking(AbstractLockedState):
+               def __init__(self,sm,callback=None):
+                       # construct a nervlist
+                       nervlist = [(OPEN_REPEAT_TIMEOUT, lambda: self.actor().act(Actor.CMD_UNLOCK)) for t in range(OPEN_REPEAT_NUMBER)]
+                       nervlist += [(OPEN_REPEAT_TIMEOUT, self.could_not_open)]
+                       super().__init__(sm,nervlist)
+                       self.callbacks = []
+                       self.actor().act(Actor.CMD_UNLOCK)
+                       # enqueue the callback
+                       self.handle_cmd_unlock_event(callback)
+               def notify(self, s, lastMsg):
+                       for cb in self.callbacks:
+                               cb(s, lastMsg)
+               def on_leave(self):
+                       s = "200 okay: door unlocked" if not self.pins().door_locked else ("500 internal server error: Couldn't unlock door with %d tries à %f seconds" % (OPEN_REPEAT_NUMBER,OPEN_REPEAT_TIMEOUT))
+                       self.notify(s, lastMsg=True)
+               def handle_cmd_unlock_event(self,callback):
+                       if callback is not None:
+                               callback("202 processing: Trying to unlock the door", lastMsg=False)
+                               self.callbacks.append(callback)
+               def could_not_open(self):
+                       logger.critical("StateMachine: Couldn't open door after %d tries. Going back to StateZu." % OPEN_REPEAT_NUMBER)
+                       return StateMachine.StateZu(self.state_machine)
+       
+       class AbstractStateWhereUnlockingIsRedundant(AbstractUnlockedState):
+               def handle_cmd_unlock_event(self, callback):

                        callback("299 redundant: Space seems to be already open. Still processing your request tough.")
                        callback("299 redundant: Space seems to be already open. Still processing your request tough.")

-                       logger.warning("Received OPEN command in StateAboutToOpen. This should not be necessary.")
-                       self.actor().act(Actor.CMD_OPEN)
+                       logger.info("StateMachine: Received UNLOCK command in %s. This should not be necessary." % self.__class__.__name__)
+                       self.actor().act(Actor.CMD_UNLOCK)

        
        

-       class StateAboutToOpen(AbstractStateWhereOpeningIsRedundant):
+       class StateAboutToOpen(AbstractStateWhereUnlockingIsRedundant):

                def __init__(self, sm):
                def __init__(self, sm):

-                       AbstractStateWhereOpeningIsRedundant.__init__(sm)
+                       super().__init__(sm, ABOUTOPEN_NERVLIST)

                def handle_pins_event(self):
                        pins = self.pins()
                def handle_pins_event(self):
                        pins = self.pins()

-                       if pins.door_locked:
-                               return StateZu(self.state_machine)
-                       elif pins.space_active:
-                               return StateAuf(self.state_machine)
-               def handle_wakeup_event(self):
-                       now = time.time()
-                       lasttime = self.last_wakeup - self.time_entered
-                       thistime = now - self.time_entered
-                       for (t,f) in filter(lambda (t,f): t<=thistime and t>lasttime, ABOUTOPEN_NERVLIST):
-                               ret = f();
-                               if ret is not None:
-                                       return ret
-       
-       class StateAuf(AbstractStateWhereOpeningIsRedundant):
+                       if pins.space_active:
+                               logger.info("Space activated, opening procedure completed")
+                               if not self.old_pins().space_active and random.random() <= SWITCH_PRAISE_PROBABILITY:
+                                       play_sound("success")
+                               return StateMachine.StateAuf(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class StateAuf(AbstractStateWhereUnlockingIsRedundant):

                def __init__(self,sm):
                def __init__(self,sm):

-                       AbstractStateWhereOpeningIsRedundant.__init__(sm)
+                       nervlist = [(24*60*60, lambda: logger.critical("Space is now open for 24h. Is everything all right?"))]
+                       super().__init__(sm, nervlist)

                        self.last_buzzed = None
                        self.last_buzzed = None

+                       self.api().set_state(True)

                def handle_pins_event(self):
                        pins = self.pins()
                def handle_pins_event(self):
                        pins = self.pins()

-                       if pins.bell_ringing:
-                               now = time.time()
-                               if self.last_buzzed is None or now-self.last_buzzed < AUF_BELLBUZZ_REPEAT_TIME:
-                                       logger.info("buzzing because of bell ringing in state auf")
-                                       self.actor().act(Actor.CMD_BUZZ)
-                                       self.last_buzzed = now
+                       if pins.bell_ringing and not self.old_pins().bell_ringing: # first thing to check: edge detection
+                               # someone just pressed the bell
+                               logger.info("StateMachine: buzzing because of bell ringing in StateAuf")
+                               self.actor().act(Actor.CMD_BUZZ)

                        if not pins.space_active:
                        if not pins.space_active:

-                               logger.info("space switch off - starting leaving procedure")
-                               return StateAboutToLeave(self.state_machine)
-                       if pins.door_locked:
-                               logger.error("door manually locked, but space switch on - going to StateZu")
-                               play_sound("manual_lock")
-                               return StateZu(self.state_machine)
-               # handle_wakeup_event intentionally not overwritten
-       
-       class StateClosing(State):
-               #TODO Ralf/Conny
-               pass
-       
-       class StateAboutToLeave(State):
-               #TODO Ralf
-               pass
-       
-       class StateLeaving(State):
-               #TODO Ralf
-               pass
-       
-       def __init__(self, actor):
+                               logger.info("StateMachine: space switch turned off - starting leaving procedure")
+                               return StateMachine.StateAboutToLeave(self.state_machine)
+                       if not pins.door_closed and self.old_pins().door_closed and random.random() <= HELLO_PROBABILITY:
+                               play_sound("hello")
+                       return super().handle_pins_event()
+               def on_leave(self):
+                       self.api().set_state(False)
+       
+       class StateLocking(AbstractUnlockedState):
+               def __init__(self,sm):
+                       # construct a nervlist
+                       nervlist = [(CLOSE_REPEAT_TIMEOUT, lambda: self.actor().act(Actor.CMD_LOCK)) for t in range(CLOSE_REPEAT_NUMBER)]
+                       nervlist += [(CLOSE_REPEAT_TIMEOUT, self.could_not_close)]
+                       super().__init__(sm, nervlist)
+                       if self.pins().door_closed: # this should always be true, but just to be sure...
+                               self.actor().act(Actor.CMD_LOCK)
+               def handle_pins_event(self):
+                       pins = self.pins()
+                       if not pins.door_closed:
+                               # TODO play a sound? This shouldn't happen, door was opened while we are locking
+                               logger.warning("StateMachine: door manually opened during locking")
+                               return StateMachine.StateAboutToOpen(self.state_machine)
+                       # TODO do anything here if the switch is activated now?
+                       return super().handle_pins_event()
+               def handle_cmd_unlock_event(self,callback):
+                       callback("409 conflict: The sphinx is currently trying to lock the door. Try again later.")
+               def could_not_close(self):
+                       logger.critical("StateMachine: Couldn't close door after %d tries. Going back to StateAboutToOpen." % CLOSE_REPEAT_NUMBER)
+                       return StateMachine.StateAboutToOpen(self.state_machine)
+       
+       class StateAboutToLeave(AbstractUnlockedState):
+               def __init__(self, sm):
+                       nervlist = [(LEAVE_TIMEOUT, lambda: StateMachine.StateLocking(self.state_machine))]
+                       super().__init__(sm, nervlist)
+               def handle_pins_event(self):
+                       if not self.pins().door_closed:
+                               return StateMachine.StateLeaving(self.state_machine)
+                       if self.pins().space_active:
+                               logger.info("Space re-activated, cancelling leaving procedure")
+                               return StateMachine.StateAuf(self.state_machine)
+                       return super().handle_pins_event()
+       
+       class StateLeaving(AbstractUnlockedState):
+               def __init__(self, sm):
+                       nervlist = [(LEAVE_TIMEOUT, lambda: StateMachine.StateAboutToOpen(self.state_machine))]
+                       super().__init__(sm, nervlist)
+               def handle_pins_event(self):
+                       if self.pins().door_closed:
+                               logger.info("The space was left, locking the door")
+                               return StateMachine.StateLocking(self.state_machine)
+                       if self.pins().space_active:
+                               logger.info("Space re-activated, cancelling leaving procedure")
+                               return StateMachine.StateAuf(self.state_machine)
+                       return super().handle_pins_event()
+       
+       def __init__(self, actor, waker, api, fallback = False):

                self.actor = actor
                self.actor = actor

-               self.callback = ThreadFunction(self._callback)
-               self.current_state = StateStart(self)
+               self.api = api
+               self.callback = ThreadFunction(self._callback, name="StateMachine")
+               self.current_state = StateMachine.StateStart(self, fallback=fallback)

                self.pins = None
                self.old_pins = None
                self.pins = None
                self.old_pins = None

+               waker.register(lambda: self.callback(StateMachine.CMD_WAKEUP), 1.0) # wake up every second
+               # initially, the space is closed
+               api.set_state(False)

        
        def stop (self):
                self.callback.stop()
        
        def stop (self):
                self.callback.stop()


@@ -199,11 +341,13 @@ class StateMachine():
        def _callback(self, cmd, arg=None):
                # update pins
                if cmd == StateMachine.CMD_PINS:
        def _callback(self, cmd, arg=None):
                # update pins
                if cmd == StateMachine.CMD_PINS:

-                       self.old_pins = self.pins

                        self.pins = arg
                # handle stuff
                newstate = self.current_state.handle_event(cmd,arg) # returns None or an instance of the new state
                        self.pins = arg
                # handle stuff
                newstate = self.current_state.handle_event(cmd,arg) # returns None or an instance of the new state

+               self.old_pins = self.pins

                while newstate is not None:
                while newstate is not None:

-                       logger.info("StateMachine: new state = %s" % newstate.__class__.__name__)
+                       assert isinstance(newstate, StateMachine.State), "I should get a state"
+                       self.current_state.on_leave()
+                       logger.debug("StateMachine: Doing state transition %s -> %s" % (self.current_state.__class__.__name__, newstate.__class__.__name__))

                        self.current_state = newstate
                        newstate = self.current_state.handle_event(StateMachine.CMD_PINS, self.pins)
                        self.current_state = newstate
                        newstate = self.current_state.handle_event(StateMachine.CMD_PINS, self.pins)