m-labs · Oct 13, 2015 · Oct 13, 2015 · Oct 13, 2015
diff --git a/artiq/frontend/artiq_client.py b/artiq/frontend/artiq_client.py
@@ -224,18 +224,22 @@ def init_d(x):
     _run_subscriber(args.server, args.port, subscriber)
 
 
+def _print_log_record(record):
+    level, source, t, message = record
+    t = time.strftime("%m/%d %H:%M:%S", time.localtime(t))
+    print(level, source, t, message)
+
+
 class _LogPrinter:
     def __init__(self, init):
-        for rid, msg in init:
-            print(rid, msg)
+        for record in init:
+            _print_log_record(record)
 
-    def append(self, x):
-        rid, msg = x
-        print(rid, msg)
+    def append(self, record):
+        _print_log_record(record)
 
-    def insert(self, i, x):
-        rid, msg = x
-        print(rid, msg)
+    def insert(self, i, record):
+        _print_log_record(record)
 
     def pop(self, i=-1):
         pass

diff --git a/artiq/frontend/artiq_master.py b/artiq/frontend/artiq_master.py
@@ -6,16 +6,17 @@
 import os
 
 from artiq.protocols.pc_rpc import Server
-from artiq.protocols.sync_struct import Notifier, Publisher
+from artiq.protocols.sync_struct import Publisher
+from artiq.master.log import log_args, init_log
 from artiq.master.databases import DeviceDB, DatasetDB
 from artiq.master.scheduler import Scheduler
 from artiq.master.worker_db import get_last_rid
 from artiq.master.repository import FilesystemBackend, GitBackend, Repository
-from artiq.tools import verbosity_args, init_logger
 
 
 def get_argparser():
     parser = argparse.ArgumentParser(description="ARTIQ master")
+
     group = parser.add_argument_group("network")
     group.add_argument(
         "--bind", default="::1",
@@ -26,37 +27,29 @@ def get_argparser():
     group.add_argument(
         "--port-control", default=3251, type=int,
         help="TCP port to listen to for control (default: %(default)d)")
+
     group = parser.add_argument_group("databases")
     group.add_argument("--device-db", default="device_db.pyon",
                        help="device database file (default: '%(default)s')")
     group.add_argument("--dataset-db", default="dataset_db.pyon",
                        help="dataset file (default: '%(default)s')")
+
     group = parser.add_argument_group("repository")
     group.add_argument(
         "-g", "--git", default=False, action="store_true",
         help="use the Git repository backend")
     group.add_argument(
         "-r", "--repository", default="repository",
         help="path to the repository (default: '%(default)s')")
-    verbosity_args(parser)
-    return parser
-
 
-class Log:
-    def __init__(self, depth):
-        self.depth = depth
-        self.data = Notifier([])
+    log_args(parser)
 
-    def log(self, rid, message):
-        if len(self.data.read) >= self.depth:
-            del self.data[0]
-        self.data.append((rid, message))
-    log.worker_pass_rid = True
+    return parser
 
 
 def main():
     args = get_argparser().parse_args()
-    init_logger(args)
+    log_buffer, log_forwarder = init_log(args)
     if os.name == "nt":
         loop = asyncio.ProactorEventLoop()
         asyncio.set_event_loop(loop)
@@ -68,13 +61,13 @@ def main():
     dataset_db = DatasetDB(args.dataset_db)
     dataset_db.start()
     atexit.register(lambda: loop.run_until_complete(dataset_db.stop()))
-    log = Log(1000)
 
     if args.git:
         repo_backend = GitBackend(args.repository)
     else:
         repo_backend = FilesystemBackend(args.repository)
-    repository = Repository(repo_backend, device_db.get_device_db, log.log)
+    repository = Repository(repo_backend, device_db.get_device_db,
+                            log_forwarder.log_worker)
     atexit.register(repository.close)
     repository.scan_async()
 
@@ -83,7 +76,7 @@ def main():
         "get_device": device_db.get,
         "get_dataset": dataset_db.get,
         "update_dataset": dataset_db.update,
-        "log": log.log
+        "log": log_forwarder.log_worker
     }
     scheduler = Scheduler(get_last_rid() + 1, worker_handlers, repo_backend)
     worker_handlers["scheduler_submit"] = scheduler.submit
@@ -105,7 +98,7 @@ def main():
         "devices": device_db.data,
         "datasets": dataset_db.data,
         "explist": repository.explist,
-        "log": log.data
+        "log": log_buffer.data
     })
     loop.run_until_complete(server_notify.start(
         args.bind, args.port_notify))

diff --git a/artiq/gui/log.py b/artiq/gui/log.py
@@ -1,4 +1,6 @@
 import asyncio
+import logging
+import time
 
 from quamash import QtGui, QtCore
 from pyqtgraph import dockarea
@@ -7,23 +9,59 @@
 from artiq.gui.tools import ListSyncModel
 
 
+def _level_to_name(level):
+    if level >= logging.CRITICAL:
+        return "CRITICAL"
+    if level >= logging.ERROR:
+        return "ERROR"
+    if level >= logging.WARNING:
+        return "WARNING"
+    if level >= logging.INFO:
+        return "INFO"
+    return "DEBUG"
+
 class _LogModel(ListSyncModel):
     def __init__(self, parent, init):
         ListSyncModel.__init__(self,
-            ["RID", "Message"],
+            ["Level", "Source", "Time", "Message"],
             parent, init)
         self.fixed_font = QtGui.QFont()
         self.fixed_font.setFamily("Monospace")
 
+        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))
+
     def data(self, index, role):
         if (role == QtCore.Qt.FontRole and index.isValid()
-                and index.column() == 1):
+                and index.column() == 3):
             return self.fixed_font
+        elif role == QtCore.Qt.BackgroundRole and index.isValid():
+            level = self.backing_store[index.row()][0]
+            if level >= logging.ERROR:
+                return self.error_bg
+            elif level >= logging.WARNING:
+                return self.warning_bg
+            else:
+                return ListSyncModel.data(self, index, role)
+        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)
         else:
             return ListSyncModel.data(self, index, role)
 
     def convert(self, v, column):
-        return v[column]
+        if column == 0:
+            return _level_to_name(v[0])
+        elif column == 1:
+            return v[1]
+        elif column == 2:
+            return time.strftime("%m/%d %H:%M:%S", time.localtime(v[2]))
+        else:
+            return v[3]
 
 
 class LogDock(dockarea.Dock):

diff --git a/artiq/master/log.py b/artiq/master/log.py
@@ -0,0 +1,95 @@
+import logging
+import time
+
+from artiq.protocols.sync_struct import Notifier
+
+
+class LogBuffer:
+    def __init__(self, depth):
+        self.depth = depth
+        self.data = Notifier([])
+
+    def log(self, level, source, message):
+        if len(self.data.read) >= self.depth:
+            del self.data[0]
+        self.data.append((level, source, time.time(), message))
+
+
+class LogBufferHandler(logging.Handler):
+    def __init__(self, log_buffer, *args, **kwargs):
+        logging.Handler.__init__(self, *args, **kwargs)
+        self.log_buffer = log_buffer
+
+    def emit(self, record):
+        message = self.format(record)
+        source = getattr(record, "source", "master")
+        self.log_buffer.log(record.levelno, source, message)
+
+
+name_to_level = {
+    "CRITICAL": logging.CRITICAL,
+    "ERROR": logging.ERROR,
+    "WARN": logging.WARNING,
+    "WARNING": logging.WARNING,
+    "INFO": logging.INFO,
+    "DEBUG": logging.DEBUG,
+}
+
+
+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
+
+
+class LogForwarder:
+    def log_worker(self, rid, message):
+        level, message = parse_log_message(message)
+        logging.log(level, message,
+                    extra={"source": "worker:{}".format(rid)})
+    log_worker.worker_pass_rid = True
+
+
+class SourceFilter:
+    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"):
+            return True
+        return record.levelno >= self.master_level
+
+
+def log_args(parser):
+    group = parser.add_argument_group("verbosity")
+    group.add_argument("-v", "--verbose", default=0, action="count",
+                       help="increase logging level for the master process")
+    group.add_argument("-q", "--quiet", default=0, action="count",
+                       help="decrease logging level for the master process")
+
+
+def init_log(args):
+    root_logger = logging.getLogger()
+    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"))
+    handlers.append(console_handler)
+
+    log_buffer = LogBuffer(1000)
+    buffer_handler = LogBufferHandler(log_buffer)
+    buffer_handler.setFormatter(logging.Formatter("%(name)s:%(message)s"))
+    handlers.append(buffer_handler)
+
+    for handler in handlers:
+        handler.addFilter(flt)
+        root_logger.addHandler(handler)
+
+    log_forwarder = LogForwarder()
+
+    return log_buffer, log_forwarder
diff --git a/doc/manual/core_device.rst b/doc/manual/core_device.rst
@@ -3,7 +3,7 @@ Core device
 
 The core device is a FPGA-based hardware component that contains a softcore CPU tightly coupled with the so-called RTIO core that provides precision timing. The CPU executes Python code that is statically compiled by the ARTIQ compiler, and communicates with the core device peripherals (TTL, DDS, etc.) over the RTIO core. This architecture provides high timing resolution, low latency, low jitter, high level programming capabilities, and good integration with the rest of the Python experiment code.
 
-While it is possible to use all the other parts of ARTIQ (controllers, master, GUI, result management, etc.) without a core device, many experiments require it.
+While it is possible to use all the other parts of ARTIQ (controllers, master, GUI, dataset management, etc.) without a core device, many experiments require it.
 
 
 .. _core-device-flash-storage:

diff --git a/doc/manual/environment.rst b/doc/manual/environment.rst
@@ -1,7 +1,7 @@
 The environment
 ===============
 
-Experiments interact with an environment that consists of devices, parameters, arguments and results. Access to the environment is handled by the class :class:`artiq.language.environment.EnvExperiment` that experiments should derive from.
+Experiments interact with an environment that consists of devices, arguments and datasets. Access to the environment is handled by the class :class:`artiq.language.environment.EnvExperiment` that experiments should derive from.
 
 .. _device-db:
 

diff --git a/doc/manual/getting_started_mgmt.rst b/doc/manual/getting_started_mgmt.rst
@@ -136,20 +136,20 @@ The master should now run the new version from its repository.
 
 As an exercise, add another argument to the experiment, commit and push the result, and verify that the new control is added in the GUI.
 
-Results
--------
+Datasets
+--------
 
 Modify the ``run()`` method of the experiment as follows: ::
 
     def run(self):
-        parabola = self.set_result("parabola", [], realtime=True)
+        parabola = self.set_dataset("parabola", [], broadcast=True)
         for i in range(int(self.count)):
             parabola.append(i*i)
             time.sleep(0.5)
 
 .. note:: You need to import the ``time`` module.
 
-Commit, push and submit the experiment as before. While it is running, go to the "Results" dock of the GUI and create a new XY plot showing the new result. Observe how the points are added one by one to the plot.
+Commit, push and submit the experiment as before. While it is running, go to the "Datasets" dock of the GUI and create a new XY plot showing the new result. Observe how the points are added one by one to the plot.
 
 After the experiment has finished executing, the results are written to a HDF5 file that resides in ``~/artiq-master/results/<date>/<time>``. Open that file with HDFView or h5dump, and observe the data we just generated as well as the Git commit ID of the experiment (a hexadecimal hash such as ``947acb1f90ae1b8862efb489a9cc29f7d4e0c645`` that represents the data at a particular time in the Git repository). The list of Git commit IDs can be found using the ``git log`` command in ``~/artiq-work``.
 

diff --git a/examples/master/repository/speed_benchmark.py b/examples/master/repository/speed_benchmark.py
@@ -101,7 +101,7 @@ def run_with_scheduler(self):
                               self.scheduler.priority, None, False)
 
     def run_without_scheduler(self, pause):
-        payload = globals()["_Payload" + self.payload](*self.dbs())
+        payload = globals()["_Payload" + self.payload](*self.managers())
 
         start_time = time.monotonic()
         for i in range(int(self.nruns)):