Repository: ManiacalLabs/BiblioPixel
Pull request #621 (2018-02-17 10:35:37)

Catch and report all exceptions from serial communication
I haven't had a chance to run this on my own strips, but they won't really test this anyway, since I don't get these errors.

Instead, I'm going to try to get the user reporting the issue to patch this commit in and see it if works better for them.  Stand by!

rec: I think it's a false optimization - the real cost of that phase is the endless list manipulation to render a buffer! - but I did it anyway.  :-D
adammhaile: Thank you. We gotta keep absolutely minimum of crap in the way of writing out to serial.
rec: I'll submit this when I see that the user with this issue can run without crashing... :-)

Patch:
diff --git a/bibliopixel/animation/animation.py b/bibliopixel/animation/animation.py
index 6c97d4a..69c4f4c 100644
--- a/bibliopixel/animation/animation.py
+++ b/bibliopixel/animation/animation.py
@@ -1,18 +1,8 @@
 import contextlib, threading, time
-from . runner import Runner
+from . runner import Runner, STATE
 from .. util import log
 from .. util.threads.animation_threading import AnimationThreading
 from .. project import attributes, fields
-from enum import IntEnum
-
-
-class STATE(IntEnum):
-    ready = 0
-    running = 1
-    complete = 2
-    canceled = 3
-    max_steps = 4
-    timeout = 5
 
 
 class BaseAnimation(object):
@@ -26,7 +16,7 @@ class BaseAnimation(object):
         "reserved fields" `name` and `data`.
         """
         a = cls(project.layout, **desc)
-        a.set_runner(run or {})
+        a._set_runner(run or {})
         a.name = name
         a.data = data
         return a
@@ -63,10 +53,7 @@ class BaseAnimation(object):
 
     @completed.setter
     def completed(self, state):
-        if state:
-            self.state = STATE.complete
-        else:
-            self.state = STATE.running
+        self.state = STATE.complete if state else STATE.running
 
     def pre_run(self):
         pass
@@ -79,34 +66,31 @@ class BaseAnimation(object):
         pass
 
     def cleanup(self, clean_layout=True):
-        # if current thread is animation thread this was called
-        # by the context manager and thread is therefore already stopped
-        if self.threading.thread != threading.current_thread():
-            self.threading.stop_thread(wait=True)
+        self.threading.cleanup()
         # Some cases we may not want to clear the screen
         # Like with the remote, it would flash between anims
         if clean_layout:
             self.layout.cleanup()
 
-    def compute_state(self):
-        if self.threading.stop_event.isSet():
-            self.state = STATE.canceled
+    def start(self):
+        self.threading.start()
 
-        elif self.runner.seconds:
-            elapsed = time.time() - self.runner.run_start_time
-            if elapsed >= self.runner.seconds:
-                self.state = STATE.timeout
+    def run_all_frames(self):
+        for i in self.generate_frames():
+            pass
 
-        elif self.runner.max_steps:
-            if self.cur_step >= self.runner.max_steps:
-                self.state = STATE.max_steps
+    def generate_frames(self, clean_layout=True):
+        with self._run_context(clean_layout):
+            while self.state == STATE.running:
+                self._run_one_frame()
+                yield
 
-        elif not self.runner.until_complete:
-            if self.state == STATE.complete:
-                # Ignore STATE.complete if until_complete is False
-                self.state = STATE.running
+    def run(self, **kwds):
+        # DEPRECATED
+        self._set_runner(kwds)
+        self.start()
 
-    def check_delay(self):
+    def _check_delay(self):
         if self.free_run:
             self.sleep_time = None
         elif self.internal_delay:
@@ -115,25 +99,16 @@ class BaseAnimation(object):
             self.sleep_time = self.runner.sleep_time
         self.layout.animation_sleep_time = self.sleep_time or 0
 
-    def run_one_frame(self):
-        timestamps = []
-
-        def stamp():
-            timestamps.append(time.time())
-
-        self.check_delay()
-
-        stamp()
+    def _run_one_frame(self):
+        timestamps = [time.time()]
 
         self.step(self.runner.amt)
-
-        stamp()
+        timestamps.append(time.time())
 
         self.layout.frame_render_time = timestamps[1] - timestamps[0]
         self.layout.push_to_driver()
 
-        stamp()
-
+        timestamps.append(time.time())
         _report_framerate(timestamps)
 
         self.cur_step += 1
@@ -142,54 +117,38 @@ class BaseAnimation(object):
                 self.cycle_count += 1
                 self.state = STATE.running
 
-        stamp()
-
         self.threading.wait(self.sleep_time, timestamps)
-
-        self.compute_state()
+        if self.threading.stop_event.isSet():
+            self.state = STATE.canceled
+        else:
+            self.state = self.runner.compute_state(self.cur_step, self.state)
 
     @contextlib.contextmanager
-    def run_context(self, clean_layout=True):
+    def _run_context(self, clean_layout=True):
         self.state = STATE.running
         self.runner.run_start_time = time.time()
         self.threading.stop_event.clear()
-        self._step = 0
+
+        self._step = 0  # DEPRECATED
         self.cur_step = 0
         self.cycle_count = 0
 
-        self.check_delay()
-
+        self._check_delay()
         self.preclear and self.layout.all_off()
         self.pre_run()
+
         try:
             yield
         finally:
             self.cleanup(clean_layout)
 
         self.on_completion and self.on_completion(self.state)
-
         self.state = STATE.ready
 
-    def run_all_frames(self, clean_layout=True):
-        with self.run_context(clean_layout):
-            while self.state == STATE.running:
-                self.run_one_frame()
-
-    def set_runner(self, runner):
-        if isinstance(runner, Runner):
-            self.runner = runner
-        else:
-            self.runner = Runner(**(runner or {}))
+    def _set_runner(self, runner):
+        self.runner = Runner(**(runner or {}))
         self.threading = AnimationThreading(self.runner, self.run_all_frames)
 
-    def start(self):
-        self.threading.start()
-
-    def run(self, **kwds):
-        # DEPRECATED
-        self.set_runner(kwds)
-        self.start()
-
 
 def _report_framerate(timestamps):
     total_time = timestamps[-1] - timestamps[0]
diff --git a/bibliopixel/animation/remote/control.py b/bibliopixel/animation/remote/control.py
index 0c0b600..4851ccf 100644
--- a/bibliopixel/animation/remote/control.py
+++ b/bibliopixel/animation/remote/control.py
@@ -85,7 +85,7 @@ class RemoteControl(collection.Collection):
             name = cfg['name']
             if name in self.name_map:
                 raise ValueError('Cannot have multiple animations with the same name: ' + name)
-            if anim:
+            if getattr(anim, 'empty', False):
                 anim.on_completion = self.on_completion
                 self.name_map[name] = i
             else:
diff --git a/bibliopixel/animation/runner.py b/bibliopixel/animation/runner.py
index 5ee2e11..760ee15 100644
--- a/bibliopixel/animation/runner.py
+++ b/bibliopixel/animation/runner.py
@@ -1,7 +1,18 @@
+import time
+from enum import IntEnum
 from .. util import log
 from .. project import attributes, load
 
 
+class STATE(IntEnum):
+    ready = 0
+    running = 1
+    complete = 2
+    canceled = 3
+    max_steps = 4
+    timeout = 5
+
+
 class Runner(object):
 
     def __init__(self, *, amt=1, fps=None, sleep_time=0, max_steps=0,
@@ -46,3 +57,20 @@ class Runner(object):
     @fps.setter
     def fps(self, fps):
         self.sleep_time = 1 / fps
+
+    def compute_state(self, cur_step, state):
+        if self.seconds:
+            elapsed = time.time() - self.run_start_time
+            if elapsed >= self.seconds:
+                return STATE.timeout
+
+        elif self.max_steps:
+            if cur_step >= self.max_steps:
+                return STATE.max_steps
+
+        elif not self.until_complete:
+            if state == STATE.complete:
+                # Ignore STATE.complete if until_complete is False
+                return STATE.running
+
+        return state
diff --git a/bibliopixel/animation/sequence.py b/bibliopixel/animation/sequence.py
index b8fd087..4126f69 100644
--- a/bibliopixel/animation/sequence.py
+++ b/bibliopixel/animation/sequence.py
@@ -23,24 +23,37 @@ class Sequence(collection.Collection):
     def restart(self):
         self.random and rand.shuffle(self.animations)
         self.index = 0
+        self._load_animation()
 
     def pre_run(self):
+        self.offset = 0
         self.restart()
 
     def step(self, amt=1):
-        if not self.animations:
+        if not self.animations or self.completed:
             return
 
-        if not self.completed:
-            log.debug('Sequence: %s', self.current_animation.title)
-            if self.length:
-                length = self.length[self.cur_step % len(self.length)]
-                self.current_animation.runner.seconds = length
-            self.current_animation.run_all_frames(clean_layout=False)
+        try:
+            next(self.frames)
+            return
+        except StopIteration:
+            pass
 
         self.index += 1
-        if self.index >= len(self.animations):
-            if self.runner.until_complete:
-                self.completed = True
-            else:
-                self.restart()
+        if self.index < len(self.animations):
+            self._load_animation()
+
+        elif self.runner.until_complete:
+            self.completed = True
+
+        else:
+            self.offset += len(self.animations)
+            self.restart()
+
+    def _load_animation(self):
+        log.debug('Sequence: %s', self.current_animation.title)
+        if self.length:
+            step = self.offset + self.index
+            length = self.length[step % len(self.length)]
+            self.current_animation.runner.seconds = length
+        self.frames = self.current_animation.generate_frames(False)
diff --git a/bibliopixel/drivers/return_codes.py b/bibliopixel/drivers/return_codes.py
index 4182d85..5d8cb17 100644
--- a/bibliopixel/drivers/return_codes.py
+++ b/bibliopixel/drivers/return_codes.py
@@ -29,7 +29,7 @@ class BiblioSerialError(Exception):
 
 def print_error(error):
     msg = RETURN_CODE_ERRORS.get(error, 'Unknown error occured.')
-    return '%s: %s' % (error, msg)
+    log.error('%s: %s', error, msg)
 
 
 def raise_error(error):
diff --git a/bibliopixel/drivers/serial/driver.py b/bibliopixel/drivers/serial/driver.py
index 8861ff0..6f83308 100644
--- a/bibliopixel/drivers/serial/driver.py
+++ b/bibliopixel/drivers/serial/driver.py
@@ -47,7 +47,7 @@ class Serial(DriverBase):
         if resp == RETURN_CODES.REBOOT:  # reboot needed
             log.info(
                 "Reconfigure and reboot needed, waiting for controller to restart...")
-            self._com.close()
+            self._close()
             time.sleep(restart_timeout)
             resp = self._connect()
             if resp != RETURN_CODES.SUCCESS:
@@ -65,7 +65,7 @@ class Serial(DriverBase):
     def cleanup(self):
         if self._com:
             log.info("Closing connection to: %s", self.dev)
-            self._com.close()
+            self._close()
 
     def _connect(self):
         try:
@@ -98,9 +98,9 @@ class Serial(DriverBase):
             packet.append(byteCount & 0xFF)  # set 1st byte of byteCount
             packet.append(byteCount >> 8)  # set 2nd byte of byteCount
             packet.append(self._spi_speed)
-            self._com.write(packet)
+            self._write(packet)
 
-            resp = self._com.read(1)
+            resp = self._read(1) or ''
             if len(resp) == 0:
                 self.devices.error()
 
@@ -117,22 +117,24 @@ class Serial(DriverBase):
         super().set_brightness(brightness)
         packet = util.generate_header(CMDTYPE.BRIGHTNESS, 1)
         packet.append(self._brightness)
-        self._com.write(packet)
-        resp = ord(self._com.read(1))
+        self._write(packet)
+        resp = self._read(1) or chr(RETURN_CODES.ERROR)
         if resp == RETURN_CODES.SUCCESS:
             return True
         print_error(resp)
 
     def _send_packet(self):
-        self._com.write(self._packet)
+        self._write(self._packet)
 
-        resp = self._com.read(1)
+        resp = self._read(1)
+        if resp is None:
+            return
         if len(resp) == 0:
             self.devices.error(fail=False)
         elif ord(resp) != RETURN_CODES.SUCCESS:
             print_error(ord(resp))
         else:
-            self._com.flushInput()
+            self._flushInput()
             return True
 
     def _compute_packet(self):
@@ -144,7 +146,31 @@ class Serial(DriverBase):
         self._packet.extend([0] * self._bufPad)
 
     def _send_sync(self):
-        self._com.write(self._sync_packet)
+        self._write(self._sync_packet)
+
+    def _read(self, *args):
+        try:
+            return self._com.read(*args)
+        except Exception as e:
+            log.error('Serial exception %s in read', e)
+
+    def _close(self):
+        try:
+            return self._com.close()
+        except Exception as e:
+            log.error('Serial exception %s in close', e)
+
+    def _write(self, packet):
+        try:
+            return self._com.write(packet)
+        except Exception as e:
+            log.error('Serial exception %s in write', e)
+
+    def _flushInput(self):
+        try:
+            return self._com._flushInput()
+        except Exception as e:
+            log.error('Serial exception %s in write', e)
 
 
 # This is DEPRECATED.
diff --git a/bibliopixel/project/project.py b/bibliopixel/project/project.py
index e623da8..45399b8 100644
--- a/bibliopixel/project/project.py
+++ b/bibliopixel/project/project.py
@@ -1,5 +1,7 @@
+import traceback
 from . import attributes, construct, cleanup, defaults, load, recurse
-from .. util import exception, json
+from .. util import exception, json, log
+from .. animation import BaseAnimation
 
 
 class Project:
@@ -16,27 +18,40 @@ class Project:
         return datatype(**kwds)
 
     def __init__(self, *, drivers, layout, maker, path, animation, **kwds):
-        attributes.check(kwds, 'project')
-        self.path = path
-        layout = layout or cleanup.cleanup_layout(animation)
-
-        self.maker = self.construct_child(**maker)
-
         def post(desc):
             return self.construct_child(**desc)
 
-        def create(root, name):
+        def create(root, name, recover=None):
             with exception.add('Unable to create ' + name):
                 return recurse.recurse(
                     root,
                     pre=None,
                     post=post,
-                    python_path='bibliopixel.' + name)
+                    python_path='bibliopixel.' + name,
+                    recover=recover)
 
+        attributes.check(kwds, 'project')
+        self.path = path
+        layout = layout or cleanup.cleanup_layout(animation)
+
+        self.maker = self.construct_child(**maker)
         self.drivers = [create(d, 'drivers') for d in drivers]
         with exception.add('Unable to create layout'):
-            self.layout = self.construct_child(**layout)
-        self.animation = create(animation, 'animation')
+            layout = self.layout = self.construct_child(**layout)
+
+        class Empty(BaseAnimation):
+            def __init__(self, desc, exception):
+                super().__init__(layout)
+                self._set_runner({})
+                log.error('Unable to create animation for %s', desc)
+                debug = log.get_log_level() <= log.DEBUG
+                msg = traceback.format_exc() if debug else str(exception)
+                log.error('\n%s', msg)
+                self.desc = desc
+                self.exception = exception
+                self.empty = True
+
+        self.animation = create(animation, 'animation', Empty)
 
 
 def project(*descs, root_file=None):
diff --git a/bibliopixel/project/recurse.py b/bibliopixel/project/recurse.py
index a9caa4d..cbe51fe 100644
--- a/bibliopixel/project/recurse.py
+++ b/bibliopixel/project/recurse.py
@@ -17,7 +17,8 @@ children.
 """
 
 
-def recurse(desc, pre='pre_recursion', post=None, python_path=None):
+def recurse(desc, pre='pre_recursion', post=None, python_path=None,
+            recover=None):
     """
     Depth first recursion through a dictionary containing type constructors
 
@@ -42,23 +43,28 @@ def recurse(desc, pre='pre_recursion', post=None, python_path=None):
             f = getattr(datatype, f, None)
         return f and f(desc)
 
-    # Automatically load strings that look like JSON or Yaml filenames.
-    desc = load.load_if_filename(desc) or desc
-    desc = construct.to_type_constructor(desc, python_path)
-    datatype = desc.get('datatype')
+    try:
+        # Automatically load strings that look like JSON or Yaml filenames.
+        desc = load.load_if_filename(desc) or desc
+        desc = construct.to_type_constructor(desc, python_path)
+        datatype = desc.get('datatype')
 
-    desc = call(pre, desc) or desc
+        desc = call(pre, desc) or desc
 
-    for child_name in getattr(datatype, 'CHILDREN', []):
-        child = desc.get(child_name)
-        if child:
-            new_path = python_path or ('bibliopixel.' + child_name)
-            if child_name.endswith('s'):
-                if isinstance(child, (dict, str)):
-                    child = [child]
-                for i, c in enumerate(child):
-                    child[i] = recurse(c, pre, post, new_path)
-            else:
-                desc[child_name] = recurse(child, pre, post, new_path)
+        for child_name in getattr(datatype, 'CHILDREN', []):
+            child = desc.get(child_name)
+            if child:
+                new_path = python_path or ('bibliopixel.' + child_name)
+                if child_name.endswith('s'):
+                    if isinstance(child, (dict, str)):
+                        child = [child]
+                    for i, c in enumerate(child):
+                        child[i] = recurse(c, pre, post, new_path)
+                else:
+                    desc[child_name] = recurse(child, pre, post, new_path)
 
-    return call(post, desc) or desc
+        return call(post, desc) or desc
+    except Exception as e:
+        if recover:
+            return recover(desc, e)
+        raise
diff --git a/bibliopixel/util/log.py b/bibliopixel/util/log.py
index 4de01f0..87ad453 100644
--- a/bibliopixel/util/log.py
+++ b/bibliopixel/util/log.py
@@ -103,6 +103,10 @@ def set_log_level(level):
     logger.setLevel(level)
 
 
+def get_log_level():
+    return logger.getEffectiveLevel()
+
+
 # Add a new logging level FRAME for messages which appear on every frame.
 _addLoggingLevel('FRAME', FRAME)
 logger = _new_custom_logger()
diff --git a/bibliopixel/util/threads/animation_threading.py b/bibliopixel/util/threads/animation_threading.py
index 4cb5d42..203200f 100644
--- a/bibliopixel/util/threads/animation_threading.py
+++ b/bibliopixel/util/threads/animation_threading.py
@@ -15,11 +15,13 @@ class AnimationThreading(object):
         self.thread = None
         self.frame_overrun = False
 
-    def stop_thread(self, wait=False):
-        # run regardless of threaded, used to stop sequences
-        self.stop_event.set()
-        if self.thread and wait:
-            self.thread.join()
+    def cleanup(self, wait=False):
+        # if current thread is animation thread this was called
+        # by the context manager and thread is therefore already stopped
+        if self.thread != threading.current_thread():
+            self.stop_event.set()
+            if self.thread and wait:
+                self.thread.join()
 
     def stopped(self):
         return not (self.thread and self.thread.isAlive())
diff --git a/projects/99-remote-matrix.json b/projects/99-remote-matrix.json
index 83c1f9b..0084a81 100644
--- a/projects/99-remote-matrix.json
+++ b/projects/99-remote-matrix.json
@@ -16,7 +16,7 @@
         "animations": [
             {
                 "animation": {
-                    "typename": "BiblioPixelAnimations.matrix.ImageAnim.ImageAnim",
+                    "typename": "MASSIVE FAILURE",
                     "name": "ImageAnim"
                 },
                 "run": {


Test patch:
diff --git a/bibliopixel/animation/tests.py b/bibliopixel/animation/tests.py
index fd69dbd..6ade354 100644
--- a/bibliopixel/animation/tests.py
+++ b/bibliopixel/animation/tests.py
@@ -19,11 +19,9 @@ class StripChannelTest(BaseStripAnim):
         self.layout.set(4, colors.Blue)
         self.layout.set(5, colors.Blue)
 
-        color = self._step % 4
+        color = self.cur_step % 4
         self.layout.fill(self.colors[color], 7, 9)
 
-        self._step += 1
-
 
 class MatrixChannelTest(BaseMatrixAnim):
 
@@ -41,11 +39,9 @@ class MatrixChannelTest(BaseMatrixAnim):
         self.layout.drawLine(4, 0, 4, self.height - 1, colors.Blue)
         self.layout.drawLine(5, 0, 5, self.height - 1, colors.Blue)
 
-        color = self._step % 4
+        color = self.cur_step % 4
         self.layout.fillRect(7, 0, 3, self.height, self.colors[color])
 
-        self._step += 1
-
 
 class MatrixCalibrationTest(BaseMatrixAnim):
 
@@ -57,11 +53,9 @@ class MatrixCalibrationTest(BaseMatrixAnim):
 
     def step(self, amt=1):
         self.layout.all_off()
-        i = self._step % self.width
+        i = self.cur_step % self.width
         for x in range(i + 1):
             c = self.colors[x % len(self.colors)]
             self.layout.drawLine(x, 0, x, i, c)
 
         self.completed = (i == (self.width - 1))
-
-        self._step += 1
diff --git a/test/bibliopixel/project/bad_project_test.py b/test/bibliopixel/project/bad_project_test.py
index 59390bb..5c6fbe4 100644
--- a/test/bibliopixel/project/bad_project_test.py
+++ b/test/bibliopixel/project/bad_project_test.py
@@ -99,20 +99,16 @@ class BadProjectTest(unittest.TestCase):
              'Unknown attribute for layout Matrix: "bad_attribute"'))
 
     def test_bad_animation_attribute(self):
-        with self.assertRaises(ValueError) as e:
-            make(BAD_ANIMATION_ATTRIBUTE)
+        animation = make(BAD_ANIMATION_ATTRIBUTE, run_start=False)
         self.assertEquals(
-            e.exception.args,
-            ('Unable to create animation',
-             'Unknown attribute for animation OffAnim: "bad_attribute"'))
+            animation.exception.args,
+            ('Unknown attribute for animation OffAnim: "bad_attribute"',))
 
     def test_bad_run_attribute(self):
-        with self.assertRaises(ValueError) as e:
-            make(BAD_RUN_ATTRIBUTE)
+        animation = make(BAD_RUN_ATTRIBUTE, run_start=False)
         self.assertEquals(
-            e.exception.args,
-            ('Unable to create animation',
-             'Unknown attribute for run: "bad_attribute"'))
+            animation.exception.args,
+            ('Unknown attribute for run: "bad_attribute"',))
 
     def test_missing_layout(self):
         with self.assertRaises(ValueError) as e: