m-labs · Oct 14, 2015 · Oct 14, 2015 · Oct 14, 2015 · Oct 14, 2015
Showing with 47 additions and 27 deletions.

+4 −2 artiq/gui/log.py

+26 −16 artiq/master/log.py

+9 −9 artiq/master/scheduler.py

+8 −0 examples/master/repository/arguments_demo.py
diff --git a/artiq/gui/log.py b/artiq/gui/log.py
@@ -28,6 +28,8 @@ def __init__(self, parent, init):
         self.fixed_font = QtGui.QFont()
         self.fixed_font.setFamily("Monospace")
 
+        self.white = QtGui.QBrush(QtGui.QColor(255, 255, 255))
+        self.black = QtGui.QBrush(QtGui.QColor(0, 0, 0))
         self.debug_fg = QtGui.QBrush(QtGui.QColor(55, 55, 55))
         self.warning_bg = QtGui.QBrush(QtGui.QColor(255, 255, 180))
         self.error_bg = QtGui.QBrush(QtGui.QColor(255, 150, 150))
@@ -43,13 +45,13 @@ def data(self, index, role):
             elif level >= logging.WARNING:
                 return self.warning_bg
             else:
-                return ListSyncModel.data(self, index, role)
+                return self.white
         elif role == QtCore.Qt.ForegroundRole and index.isValid():
             level = self.backing_store[index.row()][0]
             if level <= logging.DEBUG:
                 return self.debug_fg
             else:
-                return ListSyncModel.data(self, index, role)
+                return self.black
         else:
             return ListSyncModel.data(self, index, role)
 

diff --git a/artiq/master/log.py b/artiq/master/log.py
@@ -1,5 +1,4 @@
 import logging
-import time
 
 from artiq.protocols.sync_struct import Notifier
 
@@ -9,10 +8,10 @@ def __init__(self, depth):
         self.depth = depth
         self.data = Notifier([])
 
-    def log(self, level, source, message):
+    def log(self, level, source, time, message):
         if len(self.data.read) >= self.depth:
             del self.data[0]
-        self.data.append((level, source, time.time(), message))
+        self.data.append((level, source, time, message))
 
 
 class LogBufferHandler(logging.Handler):
@@ -22,8 +21,7 @@ def __init__(self, log_buffer, *args, **kwargs):
 
     def emit(self, record):
         message = self.format(record)
-        source = getattr(record, "source", "master")
-        self.log_buffer.log(record.levelno, source, message)
+        self.log_buffer.log(record.levelno, record.source, record.created, message)
 
 
 name_to_level = {
@@ -39,15 +37,24 @@ def emit(self, record):
 def parse_log_message(msg):
     for name, level in name_to_level.items():
         if msg.startswith(name + ":"):
-            return level, msg[len(name) + 1:]
-    return logging.INFO, msg
+            remainder = msg[len(name) + 1:]
+            try:
+                idx = remainder.index(":")
+            except:
+                continue
+            return level, remainder[:idx], remainder[idx+1:]
+    return logging.INFO, "print", msg
+
+
+fwd_logger = logging.getLogger("fwd")
 
 
 class LogForwarder:
     def log_worker(self, rid, message):
-        level, message = parse_log_message(message)
-        logging.log(level, message,
-                    extra={"source": "worker:{}".format(rid)})
+        level, name, message = parse_log_message(message)
+        fwd_logger.name = name
+        fwd_logger.log(level, message,
+                       extra={"source": "worker({})".format(rid)})
     log_worker.worker_pass_rid = True
 
 
@@ -56,11 +63,14 @@ def __init__(self, master_level):
         self.master_level = master_level
 
     def filter(self, record):
-        # log messages that are forwarded from a source have already
-        # been filtered, and may have a level below the master level.
-        if hasattr(record, "source"):
+        if not hasattr(record, "source"):
+            record.source = "master"
+        if record.source == "master":
+            return record.levelno >= self.master_level
+        else:
+            # log messages that are forwarded from a source have already
+            # been filtered, and may have a level below the master level.
             return True
-        return record.levelno >= self.master_level
 
 
 def log_args(parser):
@@ -73,12 +83,12 @@ def log_args(parser):
 
 def init_log(args):
     root_logger = logging.getLogger()
-    root_logger.setLevel(logging.NOTSET) # we use our custom filter only
+    root_logger.setLevel(logging.NOTSET)  # we use our custom filter only
     flt = SourceFilter(logging.WARNING + args.quiet*10 - args.verbose*10)
 
     handlers = []
     console_handler = logging.StreamHandler()
-    console_handler.setFormatter(logging.Formatter("%(levelname)s:%(name)s:%(message)s"))
+    console_handler.setFormatter(logging.Formatter("%(levelname)s:%(source)s:%(name)s:%(message)s"))
     handlers.append(console_handler)
 
     log_buffer = LogBuffer(1000)

diff --git a/artiq/master/scheduler.py b/artiq/master/scheduler.py
@@ -228,9 +228,9 @@ async def _do(self):
                     await run.build()
                     await run.prepare()
                 except:
-                    logger.warning("got worker exception in prepare stage, "
-                                   "deleting RID %d",
-                                   run.rid, exc_info=True)
+                    logger.error("got worker exception in prepare stage, "
+                                 "deleting RID %d",
+                                 run.rid, exc_info=True)
                     self.delete_cb(run.rid)
                 else:
                     run.status = RunStatus.prepare_done
@@ -278,9 +278,9 @@ async def _do(self):
                     run.status = RunStatus.running
                     completed = await run.run()
             except:
-                logger.warning("got worker exception in run stage, "
-                               "deleting RID %d",
-                               run.rid, exc_info=True)
+                logger.error("got worker exception in run stage, "
+                             "deleting RID %d",
+                             run.rid, exc_info=True)
                 self.delete_cb(run.rid)
             else:
                 if completed:
@@ -316,9 +316,9 @@ async def _do(self):
                 await run.analyze()
                 await run.write_results()
             except:
-                logger.warning("got worker exception in analyze stage, "
-                               "deleting RID %d",
-                               run.rid, exc_info=True)
+                logger.error("got worker exception in analyze stage, "
+                             "deleting RID %d",
+                             run.rid, exc_info=True)
                 self.delete_cb(run.rid)
             else:
                 self.delete_cb(run.rid)

diff --git a/examples/master/repository/arguments_demo.py b/examples/master/repository/arguments_demo.py
@@ -1,3 +1,5 @@
+import logging
+
 from artiq import *
 
 
@@ -51,6 +53,12 @@ def build(self):
         self.sc2 = SubComponent2(parent=self)
 
     def run(self):
+        logging.basicConfig(level=logging.DEBUG)
+        logging.error("logging test: error")
+        logging.warning("logging test: warning")
+        logging.info("logging test: info")
+        logging.debug("logging test: debug")
+
         print(self.free_value)
         print(self.boolean)
         print(self.enum)