Timer Callback KeepAlive + cleanup - 2nd

docs/api.rst

@@ -68,10 +68,18 @@ high level interface
     :members:
     :undoc-members:
 
+.. automodule:: pysimavr.logger
+    :members:
+    :undoc-members:
+
 .. automodule:: pysimavr.sgm7
     :members:
     :undoc-members:
 
+.. automodule:: pysimavr.timer
+    :members:
+    :undoc-members:  
+
 .. automodule:: pysimavr.vcdfile
     :members:
     :undoc-members:

pysimavr/avr.py

@@ -20,7 +20,8 @@ class UnkwownAvrError(Exception):
 
 class Avr(Proxy):
     _reserved = '''uart f_cpu arduino_targets avcc vcc avrsize reset mcu time_marker move_time_marker terminate goto_cycle 
-                goto_time time_passed load_firmware step step_time step_cycles getirq fpeek peek run pause states firmware timer'''.split()
+                goto_time time_passed load_firmware step step_time step_cycles getirq fpeek peek run pause states firmware 
+                timer callbacks_keepalive'''.split()
     arduino_targets = 'atmega48 atmega88 atmega168 atmega328p'.split()
 
     states = [
@@ -30,8 +31,8 @@ class Avr(Proxy):
         'Sleeping',  # we're now sleeping until an interrupt
         'Step',  # run ONE instruction, then...
         'StepDone',  # tell gdb it's all OK, and give it registers,
-        'Done', # avr software stopped gracefully
-        'Crashed' # avr software crashed (watchdog fired)
+        'Done',  # avr software stopped gracefully
+        'Crashed'  # avr software crashed (watchdog fired)
     ]
 
     def __init__(self, firmware=None, mcu=None, f_cpu=None, avcc=5, vcc=5):
@@ -43,7 +44,8 @@ def __init__(self, firmware=None, mcu=None, f_cpu=None, avcc=5, vcc=5):
         :param vcc: vcc in Volt
         '''
         if get_simavr_logger() is None:
-            init_simavr_logger() #Only init logger when it was not initialized before
+            init_simavr_logger()  # Only init logger when it was not initialized before
+        self.callbacks_keepalive = [];  # External callback instances are stored here just to avoid GC destroying them too early
         self.avrsize = None
         self.time_marker = 0.0
         self.mcu = mcu
@@ -67,7 +69,7 @@ def __init__(self, firmware=None, mcu=None, f_cpu=None, avcc=5, vcc=5):
             raise UnkwownAvrError('unknown AVR: ' + self.mcu)
 
         avr_init(self.backend)
-        self.backend.frequency = self.f_cpu #Propagate the freq to the backend
+        self.backend.frequency = self.f_cpu  # Propagate the freq to the backend
 
         self._set_voltages()
 
@@ -127,14 +129,16 @@ def terminate(self):
             return
         self._terminated = True
         log.debug('terminating...')
+        # Release references to all callbacks kept-alive so they can get GC collected. 
+        self.callbacks_keepalive = []
         avr_terminate_thread()
         avr_terminate(self.backend)
         self.uart.terminate()
         log.debug('...ok')
 
     def step(self, n=1, sync=True):
         if sync:
-            for i in range(n):
+            for _ in range(n):
                 avr_run(self.backend)
         else:
             # asynchrone
@@ -188,18 +192,20 @@ def reset(self):
         self.goto_cycle(0)
         avr_reset(self.backend)
         self.backend.cycle = 0  # no reset in simavr !
-        
-    def timer(self, callback, cycle = 0, uSec = 0):
-        """Registers a new cycle timer callback.
-        
-        :Parameters:
-            `callback` : The callback method.  Must accept and returning the cycle number.
-            `cycle` : When the callback should be called in simavr mcu cycles.
-            `uSec` : As the `cycle` but in micro-seconds. Gets converted to cycles first. 
-        
-        :Returns: a `pysimavr.timer.Timer`   
+
+    def timer(self, callback, cycle=0, uSec=0, keepalive=True):
+        """Registers a new cycle timer callback. Use either `cycle` or `uSec` parameter to schedule the notification.
+
+        :param callback: The callback function. A `callable(when)->int`. See :func:`Timer.on_timer <pysimavr.timer.Timer.on_timer>` for more details.
+        :param cycle: When the callback should be invoked. The simavr mcu cycle number.
+        :param uSec: When the callback should be invoked. The virtual time from mcu startup in micro-seconds. Gets converted to cycles internally.. 
+        :param keepalive: Whether the returned object should be referenced internally. See the :class:`~pysimavr.irq.IRQHelper` for more details.
+
+        :return: A :class:`~pysimavr.timer.Timer` instance.   
         """
         t = Timer(self, callback)
+        if keepalive:
+            self.callbacks_keepalive.append(t)
         if cycle > 0: 
             t.set_timer_cycles(cycle)
         if uSec > 0: 

pysimavr/logger.py

@@ -7,71 +7,74 @@
 
 simavr_to_py_log_level = {
         LOG_OUTPUT:logging.FATAL,
-        LOG_ERROR:logging.ERROR, 
+        LOG_ERROR:logging.ERROR,
         LOG_WARNING:logging.WARNING,
-        LOG_TRACE:logging.DEBUG        
+        LOG_TRACE:logging.DEBUG
 }
 
 
 def pylogging_log(line, avr_log_level):
     """The default logging function utilising the python logging framework."""
-    py_log_level = simavr_to_py_log_level.get(avr_log_level, logging.DEBUG )
-    if not log.isEnabledFor(py_log_level): return;        
+    py_log_level = simavr_to_py_log_level.get(avr_log_level, logging.DEBUG)
+    if not log.isEnabledFor(py_log_level): return;
     log.log(py_log_level, line.strip());
 
 
 class SimavrLogger(LoggerCallback):
     """Consumes log statements from the core simavr logger and propagates
     them to the configured callback function. The default callback function is using 
-    the `pylogging_log` which uses python logging.
-    
-    Do not create instance of this class directly but use the provided `init_simavr_logger` module function instead. 
+    the :func:`pylogging_log` which uses python logging.
+
+    Do not create instance of this class directly but use the provided :func:`init_simavr_logger` module function instead. 
     """  
 
-
     def __init__(self, callback=None):
         LoggerCallback.__init__(self)
-        #super(TimerCallback, self).__init__()
+        # super(TimerCallback, self).__init__()
         self._callback = callback
-        
+
     def on_log(self, line, avr_log_level):
+        """ Called by simavr to log a message.
+
+            :param line: The log message.
+            :param avr_log_level: Log message severity. One of the `pysimavr.swig.simavr.LOG_*` constants.
+        """
         if self._callback:
             try: self._callback(line, avr_log_level)
             except:
-                #Log any python exception here since py stacktrace is not propagated down to C++ and it would be lost
+                # Log any python exception here since py stacktrace is not propagated down to C++ and it would be lost
                 traceback.print_exc()
                 raise
-
-
+
     @property
     def callback(self):
         return self._callback;
-    
+
     @callback.setter
     def callback(self, callback):
         self._callback = callback
-        
+
 def get_simavr_logger():
+    """ :return: The global :class:`SimavrLogger` instance or `None` when not initialized yet. """
     if  '_simavr_logger' in globals():
         return globals()['_simavr_logger']
     return None 
 
-
 def init_simavr_logger(logger=pylogging_log):
     """Sets the logger callback. Use to redirect logs to a custom handler.
-    
+
     When using a custom logging function it is necessary to set the custom logger
-    before the `pysimavr.avr.Avr` is created. Otherwise some of the early simavr simavr log 
-    messages might get missed.
-    
-    Note the `avr_log_level` withe zero value (`pysimavr.swig.simavr.LOG_OUTPUT`) indicates the message is
-    an output for the simulated firmware. 
-    """  
+    before the :class:`~pysimavr.avr.Avr` is created. Otherwise some of the early simavr log 
+    messages might get lost.
+
+    Note the `avr_log_level` with zero value (`pysimavr.swig.simavr.LOG_OUTPUT`) indicates the message is
+    an output from the simulated firmware. 
+    """
     global _simavr_logger
     _simavr_logger = get_simavr_logger()
     if logger is None:
         _simavr_logger = None
         return
     if _simavr_logger is None:
         _simavr_logger = SimavrLogger()
-    _simavr_logger.callback = logger
+    _simavr_logger.callback = logger

pysimavr/timer.py

@@ -2,22 +2,25 @@
 import traceback
 
 class Timer(TimerCallback):
-    """Wraps the simavr cycle_timer functionality. Enables to hook a python method
+    """ Wraps the simavr cycle_timer functionality. Enables to hook a python method
     to be called every x simavr cycles. 
-    """        
-
+
+    Note there is usually no need to create instance of this class directly as there is a 
+    helper :func:`avr.timer <pysimavr.avr.Avr.timer>` method available.
+    """
+
     def __init__(self, avr, callback=None):
         TimerCallback.__init__(self, avr)
         #super(TimerCallback, self).__init__()
         self._callback = callback
-        
-    
+
+
     def on_timer(self, when):
         """ The callback called from simavr.
-        :Parameters:
-            `when` : The exact simavr cycle number. Note actual cycle number could be
+
+        :param when: The exact simavr cycle number. Note actual cycle number could be
                 slightly off the requested one.
-        :Returns: The new cycle number the next callback should be invoked. 
+        :return: The new cycle number the next callback should be invoked. 
                 Or zero to cancel the callback.           
         """
         if self._callback:
@@ -26,14 +29,11 @@ def on_timer(self, when):
                 #Log any python exception here since py stacktrace is not propagated down to C++ and it would be lost
                 traceback.print_exc()
                 raise
-
-
-
+
     @property
     def callback(self):
         return self._callback;
-    
+
     @callback.setter
     def callback(self, callback):
         self._callback = callback
-

tests/test_timer.py

@@ -4,25 +4,25 @@
 from nose.tools import eq_
 from pysimavr.avr import Avr
 from pysimavr.swig.simavr import cpu_Running 
-from hamcrest import assert_that, close_to, greater_than, equal_to, none, is_
+from hamcrest import assert_that, close_to, greater_than, equal_to, none, is_, not_none
 import weakref
 import gc
 
 def test_timer_simple():
-    avr = Avr(mcu='atmega88', f_cpu=8000000)    
+    avr = Avr(mcu='atmega88', f_cpu=8000000)
     # Callback method mocked out. 
     callbackMock = Mock(return_value=0)
-    
+
     #Schedule callback at 20uSec.  
     # cycles = avr->frequency * (avr_cycle_count_t)usec / 1000000;
     timer = avr.timer(callbackMock, uSec=20)
-         
+
     assert_that(timer.status(), close_to(8000000*20/1000000, 10), 
                 "uSec to cycles convertion")    
-    
+
     avr.step(1000)
     eq_(avr.state, cpu_Running, "mcu is not running")
-            
+
     eq_(callbackMock.call_count, 1, "number of calback invocations")
     avr.terminate()
 
@@ -31,44 +31,54 @@ def test_timer_reoccuring():
     # Callback method mocked out. It will register another callback 
     # at 200 cycles and then cancel by returning 0.
     callbackMock = Mock(side_effect = [200, 0])
-    
+
     timer = avr.timer(callbackMock)
     avr.step(10)
     eq_(avr.state, cpu_Running, "mcu is not running")
     callbackMock.assert_not_called()
-    
+
     # Request first timer callback at 100 cycles
     timer.set_timer_cycles(100)    
-    
+
     # Run long enought to ensure callback is canceled by returning 0 on the second invocation.
     avr.step(1000)
     eq_(avr.state, cpu_Running, "mcu is not running")
     eq_(callbackMock.call_count, 2, "number of calback invocations")
-        
+
     lastCallFirstArg = callbackMock.call_args[0][0]    
     assert_that(lastCallFirstArg, close_to(200, 10), 
                 "The last cycle number received in the callback doesn't match the requested one") 
     avr.terminate()
-    
+
 def test_timer_cancel():
     avr = Avr(mcu='atmega88', f_cpu=1000000)
     callbackMock = Mock(return_value=200)
     timer = avr.timer(callbackMock, cycle=50)    
     avr.step(10)
     callbackMock.assert_not_called()
-    
+
     timer.cancel()
     avr.step(1000)
     callbackMock.assert_not_called()    
-         
+
     avr.terminate()
-    
+
 def test_timer_GC():
     avr = Avr(mcu='atmega88', f_cpu=1000000)
     callbackMock = Mock(return_value=0)
-    t = weakref.ref(avr.timer(callbackMock, cycle=10))
+    #Don't let avr object to keep the callback referenced.
+    t = weakref.ref(avr.timer(callbackMock, cycle=10, keepalive=False))
     gc.collect()
     assert_that(t(), is_(none()), "Orphan Timer didn't get garbage collected.")
     avr.step(100)
-    assert_that(callbackMock.call_count, equal_to(0), "Number of IRQ callback invocations.")        
-    avr.terminate()
+    assert_that(callbackMock.call_count, equal_to(0), "Number of IRQ callback invocations.")
+
+    #Now let avr object keep the callback alive.
+    t = weakref.ref(avr.timer(callbackMock, cycle=110, keepalive=True))
+    gc.collect()
+    assert_that(t(), is_ (not_none()), "Avr object didn't kept Timer callback alive.")
+    avr.step(1000)
+    assert_that(callbackMock.call_count, equal_to(1), "Number of IRQ callback invocations.")                   
+    avr.terminate()
+    gc.collect()
+    assert_that(t(), is_(none()), "Orphan Timer didn't get garbage collected even after Avr is terminated.")