Do not fail on exception message formatting

artiq/coredevice/comm_kernel.py

@@ -705,8 +705,13 @@ def read_exception_string():
             python_exn_type = embedding_map.retrieve_object(core_exn.id)
 
         try:
-            python_exn = python_exn_type(
-                nested_exceptions[-1][1].format(*nested_exceptions[0][2]))
+            message = nested_exceptions[0][1].format(*nested_exceptions[0][2])
+        except:
+            message = nested_exceptions[0][1]
+            logger.error("Couldn't format exception message", exc_info=True)
+
+        try:
+            python_exn = python_exn_type(message)
         except Exception as ex:
             python_exn = RuntimeError(
                 f"Exception type={python_exn_type}, which couldn't be "

artiq/coredevice/exceptions.py

@@ -30,7 +30,12 @@
 
 
 class CoreException:
-    """Information about an exception raised or passed through the core device."""
+    """Information about an exception raised or passed through the core device.
+
+     If the exception message contains positional format arguments, it
+     will attempt to substitute them with the provided parameters.
+     If the substitution fails, the original message will remain unchanged.
+    """
     def __init__(self, exceptions, exception_info, traceback, stack_pointers):
         self.exceptions = exceptions
         self.exception_info = exception_info
@@ -92,7 +97,10 @@ def single_traceback(self, exception_index):
             exn_id = int(exn_id)
         else:
             exn_id = 0
-        lines.append("{}({}): {}".format(name, exn_id, message.format(*params)))
+        try:
+            lines.append("{}({}): {}".format(name, exn_id, message.format(*params)))
+        except:
+            lines.append("{}({}): {}".format(name, exn_id, message))
         zipped.append(((exception[3], exception[4], exception[5], exception[6],
                        None, []), None))
 

artiq/test/coredevice/test_exceptions.py

@@ -1,10 +1,94 @@
-import unittest
-import artiq.coredevice.exceptions as exceptions
+import re
 
 from artiq.experiment import *
+from artiq.master.worker_db import DeviceError
 from artiq.test.hardware_testbench import ExperimentCase
 from artiq.compiler.embedding import EmbeddingMap
 from artiq.coredevice.core import test_exception_id_sync
+import artiq.coredevice.exceptions as exceptions
+
+
+class CustomException(Exception):
+    pass
+
+
+class KernelFmtException(EnvExperiment):
+    def build(self):
+        self.setattr_device("core")
+
+    @kernel
+    def run(self):
+        self.throw()
+
+    def throw(self):
+        raise CustomException("{foo}")
+
+
+class KernelNestedFmtException(EnvExperiment):
+    def build(self):
+        self.setattr_device("core")
+
+    @kernel
+    def run(self):
+        try:
+            self.throw_foo()
+        except:
+            try:
+                raise RTIOUnderflow("{bar}")
+            except:
+                try:
+                    raise RTIOOverflow("{bizz}")
+                except:
+                    self.throw_buzz()
+
+    def throw_foo(self):
+        raise CustomException("{foo}")
+
+    def throw_buzz(self):
+        raise RTIOUnderflow("{buzz}")
+
+
+class KernelRTIOUnderflow(EnvExperiment):
+    def build(self):
+        self.setattr_device("core")
+        try:
+            self.setattr_device("led")
+        except DeviceError:
+            self.led = self.get_device("led0")
+
+    @kernel
+    def run(self):
+        self.core.reset()
+        at_mu(self.core.get_rtio_counter_mu() - 1000); self.led.on()
+
+
+class ExceptionFormatTest(ExperimentCase):
+    def test_custom_formatted_kernel_exception(self):
+        with self.assertLogs() as captured:
+            with self.assertRaisesRegex(CustomException, r"CustomException\(\d+\): \{foo\}"):
+                self.execute(KernelFmtException)
+        captured_lines = captured.output[0].split('\n')
+        self.assertEqual([captured_lines[0], captured_lines[-1]],
+                         ["ERROR:artiq.coredevice.comm_kernel:Couldn't format exception message", "KeyError: 'foo'"])
+
+    def test_nested_formatted_kernel_exception(self):
+        with self.assertLogs() as captured:
+            with self.assertRaisesRegex(CustomException,
+                                        re.compile(
+                                            r"CustomException\(\d+\): \{foo\}.*?RTIOUnderflow\(\d+\): \{bar\}.*?RTIOOverflow\(\d+\): \{bizz\}.*?RTIOUnderflow\(\d+\): \{buzz\}",
+                                            re.DOTALL)):
+                self.execute(KernelNestedFmtException)
+        captured_lines = captured.output[0].split('\n')
+        self.assertEqual([captured_lines[0], captured_lines[-1]],
+                         ["ERROR:artiq.coredevice.comm_kernel:Couldn't format exception message", "KeyError: 'foo'"])
+
+    def test_rtio_underflow(self):
+        with self.assertRaisesRegex(RTIOUnderflow,
+                                    re.compile(
+                                        r"RTIO underflow at channel 0x[0-9a-fA-F]*?:led\d*?, \d+? mu, slack -\d+? mu.*?RTIOUnderflow\(\d+\): RTIO underflow at channel 0x([0-9a-fA-F]+?):led\d*?, \d+? mu, slack -\d+? mu",
+                                        re.DOTALL)):
+            self.execute(KernelRTIOUnderflow)
+
 
 """
 Test sync in exceptions raised between host and kernel
@@ -38,7 +122,7 @@ def raise_exception_kernel(self, id):
         test_exception_id_sync(id)
 
 
-class ExceptionTest(ExperimentCase):
+class ExceptionSyncTest(ExperimentCase):
     def test_raise_exceptions_kernel(self):
         exp = self.create(_TestExceptionSync)
 
@@ -56,4 +140,3 @@ def test_raise_exceptions_host(self):
             name = name.split('.')[-1].split(':')[-1]
             with self.assertRaises(getattr(exceptions, name)) as ctx:
                 exp.raise_exception_host(id)
-

flake.nix

@@ -604,6 +604,9 @@
             # Read "Ok" line when remote successfully locked
             read LOCK_OK
 
+            artiq_rtiomap --device-db $ARTIQ_ROOT/device_db.py device_map.bin
+            artiq_mkfs -s ip `python -c "import artiq.examples.kc705_nist_clock.device_db as ddb; print(ddb.core_addr)"`/24 -f device_map device_map.bin kc705_nist_clock.config
+            artiq_flash -t kc705 -H rpi-1 storage -f kc705_nist_clock.config
             artiq_flash -t kc705 -H rpi-1 -d ${packages.x86_64-linux.artiq-board-kc705-nist_clock}
             sleep 30