diff --git a/qcodes/__init__.py b/qcodes/__init__.py index f7a65d3adeab..47372115118f 100644 --- a/qcodes/__init__.py +++ b/qcodes/__init__.py @@ -10,6 +10,11 @@ from qcodes.process.helpers import set_mp_method from qcodes.utils.helpers import in_notebook +config=dict({'logging': {'usezmq': 1} }) +if config['logging']['usezmq']: + from qcodes.utils.loggingGUI import installZMQlogger + qlogger=installZMQlogger() + # code that should only be imported into the main (notebook) thread # in particular, importing matplotlib in the side processes takes a long # time and spins up other processes in order to try and get a front end diff --git a/qcodes/process/server.py b/qcodes/process/server.py index 7acc408bd720..cbb8c201ec64 100644 --- a/qcodes/process/server.py +++ b/qcodes/process/server.py @@ -5,6 +5,8 @@ from uuid import uuid4 import builtins import logging +import time +from multiprocessing import current_process QUERY_WRITE = 'WRITE' QUERY_ASK = 'ASK' @@ -14,6 +16,8 @@ from qcodes.utils.nested_attrs import NestedAttrAccess from .qcodes_process import QcodesProcess from .helpers import kill_queue +from qcodes import config +from qcodes.utils import loggingGUI class ServerManager: @@ -282,10 +286,22 @@ def run_event_loop(self): it's not by setting `self.running = False`) """ self.running = True + + if config['logging']['usezmq']: + if self.timeout == None: + self.timeout = 5 + _ = loggingGUI.installZMQlogger() + logging.info('run_event_loop') + prev_time = time.time() while self.running: query = self._query_queue.get(timeout=self.timeout) self.process_query(query) + if (time.time() - prev_time) > .1: + logging.info('heartbeat of %s: alive... %s' % + (current_process().name, time.ctime())) + prev_time = time.time() + def process_query(self, query): """ Act on one query received through the query queue. diff --git a/qcodes/utils/loggingGUI.py b/qcodes/utils/loggingGUI.py new file mode 100644 index 000000000000..585bd06e7e63 --- /dev/null +++ b/qcodes/utils/loggingGUI.py @@ -0,0 +1,260 @@ +""" +A GUI for multi-processing logging using ZMQ + +Code is adapted from https://github.com/zeromq/pyzmq/blob/master/examples/logger/zmqlogger.py + +Pieter Eendebak + +""" + +#%% Import packages +import logging +import os +import signal +import time +import argparse +import re + +from qtpy import QtGui +from qtpy import QtWidgets + + +import zmq +import zmq.log.handlers +from zmq.log.handlers import PUBHandler + +#%% Util functions + + +def static_var(varname, value): + """ Helper function to create a static variable """ + def decorate(func): + setattr(func, varname, value) + return func + return decorate + + +@static_var("time", 0) +def tprint(string, dt=1, output=False): + """ Print progress of a loop every dt seconds """ + if (time.time() - tprint.time) > dt: + print(string) + tprint.time = time.time() + if output: + return True + else: + return + else: + if output: + return False + else: + return + +#%% Functions for installing the logger + + +def removeZMQlogger(name=None): + logger = logging.getLogger(name) + + for h in logger.handlers: + if isinstance(h, zmq.log.handlers.PUBHandler): + print('removing handler %s' % h) + logger.removeHandler(h) + + +def installZMQlogger(port=5800, name=None, clear=True, level=logging.INFO): + if clear: + removeZMQlogger(name) + + ctx = zmq.Context() + pub = ctx.socket(zmq.PUB) + pub.setsockopt(zmq.RCVHWM, 10) + + pub.connect('tcp://127.0.0.1:%i' % port) + + if name is None: + rootlogger = logging.getLogger() + else: + rootlogger = logging.getLogger(name) + if level is not None: + rootlogger.setLevel(level) + handler = PUBHandler(pub) + pid = os.getpid() + pstr = 'pid %d: ' % pid + handler.formatters = { + logging.DEBUG: logging.Formatter(pstr + + "%(levelname)s %(filename)s:%(lineno)d - %(message)s\n"), + logging.INFO: logging.Formatter(pstr + "%(message)s\n"), + logging.WARN: logging.Formatter(pstr + + "%(levelname)s %(filename)s:%(lineno)d - %(message)s\n"), + logging.ERROR: logging.Formatter(pstr + + "%(levelname)s %(filename)s:%(lineno)d - %(message)s - %(exc_info)s\n"), + logging.CRITICAL: logging.Formatter(pstr + + "%(levelname)s %(filename)s:%(lineno)d - %(message)s\n")} + + rootlogger.addHandler(handler) + logging.debug('installZMQlogger: handler installed') + # first message always is discarded + return rootlogger + +#%% + + +class zmqLoggingGUI(QtWidgets.QDialog): + + LOG_LEVELS = dict({logging.DEBUG: 'debug', logging.INFO: 'info', + logging.WARN: 'warning', logging.ERROR: 'error', logging.CRITICAL: 'critical'}) + + def __init__(self, parent=None): + super(zmqLoggingGUI, self).__init__(parent) + + self.setWindowTitle('ZMQ logger') + + self.imap = dict((v, k) for k, v in self.LOG_LEVELS.items()) + + self._console = QtWidgets.QPlainTextEdit(self) + self._console.setMaximumBlockCount(2000) + + self._button = QtWidgets.QPushButton(self) + self._button.setText('Clear') + self._killbutton = QtWidgets.QPushButton(self) + self._killbutton.setText('Kill processes') + + self._levelBox = QtWidgets.QComboBox(self) + for k in sorted(self.LOG_LEVELS.keys()): + print('item %s' % k) + val = self.LOG_LEVELS[k] + self._levelBox.insertItem(k, val) + + blayout = QtWidgets.QHBoxLayout() + blayout.addWidget(self._button) + blayout.addWidget(self._killbutton) + blayout.addWidget(self._levelBox) + self._button.clicked.connect(self.clearMessages) + self._killbutton.clicked.connect(self.killPID) + self._levelBox.currentIndexChanged.connect(self.setLevel) + + layout = QtWidgets.QVBoxLayout() + layout.addWidget(self._console) + layout.addLayout(blayout) + self.setLayout(layout) + + self.addMessage('logging started...' + '\n') + + self._levelBox.setCurrentIndex(1) + self.loglevel = logging.INFO + self.nkill = 0 + + def setLevel(self, boxidx): + name = self._levelBox.itemText(boxidx) + lvl = self.imap.get(name, None) + print('set level to %s: %d' % (name, lvl)) + if lvl is not None: + self.loglevel = lvl + + def addMessage(self, msg, level=None): + if level is not None: + if level < self.loglevel: + return + self._console.moveCursor(QtGui.QTextCursor.End) + self._console.insertPlainText(msg) + self._console.moveCursor(QtGui.QTextCursor.End) + + def clearMessages(self): + ''' Clear the messages in the logging window ''' + self._console.clear() + self.addMessage('cleared messages...\n') + + def killPID(self): + ''' Clear the messages in the logging window ''' + self.nkill = 10 + + +def qt_logger(port, dlg, level=logging.INFO, verbose=1): + ctx = zmq.Context() + sub = ctx.socket(zmq.SUB) + sub.bind('tcp://127.0.0.1:%i' % port) + sub.setsockopt(zmq.SUBSCRIBE, b"") + sub.setsockopt(zmq.RCVHWM, 10) + + logging.basicConfig(level=level) + app = QtWidgets.QApplication.instance() + app.processEvents() + + print('connected to port %s' % port) + while True: + tprint('ZMQ logger: logging...', dt=5) + try: + level, message = sub.recv_multipart(zmq.NOBLOCK) + # level, message = sub.recv_multipart() + message = message.decode('ascii') + if message.endswith('\n'): + # trim trailing newline, which will get appended again + message = message[:-1] + level = level.lower().decode('ascii') + log = getattr(logging, level) + lvlvalue = dlg.imap.get(level, None) + + if verbose >= 2: + log(message) + dlg.addMessage(message + '\n', lvlvalue) + + if dlg.nkill > 0: + print('checking pid to kill') + m = re.match('pid (\d*): ', message) + dlg.nkill = dlg.nkill - 1 + if m is not None: + pid = int(m.group(1)) + print('killing pid %d' % pid) + mysignal = getattr(signal, 'SIGKILL', signal.SIGTERM) + os.kill(pid, mysignal) # or signal.SIGKILL + dlg.addMessage( + 'send kill signal to pid %d\n' % pid, logging.CRITICAL) + app.processEvents() + + if verbose >= 2: + print('message: %s (level %s)' % (message, level)) + except zmq.error.Again: + # no messages in system.... + app.processEvents() + time.sleep(.1) + message = '' + level = None + + if dlg.nkill>0: + time.sleep(.1) + dlg.nkill=max(dlg.nkill-1, 0) + +#%% +if __name__=='__main__': + parser = argparse.ArgumentParser() + parser.add_argument('-v', '--verbose', default=1, help="verbosity level") + parser.add_argument( + '-l', '--level', default=logging.DEBUG, help="logging level") + parser.add_argument('-p', '--port', type=int, default=5800, help="zmq port") + parser.add_argument('-g', '--gui', type=int, default=1, help="show gui") + args = parser.parse_args() + + +if __name__ == '__main__': + + port = args.port + verbose = args.verbose + + app = None + if (not QtWidgets.QApplication.instance()): + app = QtWidgets.QApplication([]) + dlg = zmqLoggingGUI() + dlg.resize(800, 400) + dlg.show() + + # start the log watcher + try: + qt_logger(port, level=args.level, verbose=verbose, dlg=dlg) + except KeyboardInterrupt: + pass + + # if (app): + # app.exec_() + +