diff options
| -rw-r--r-- | changes/bug-7222_run-background-zmq-subscriber | 1 | ||||
| -rw-r--r-- | src/leap/bitmask/gui/logwindow.py | 119 | ||||
| -rw-r--r-- | src/leap/bitmask/gui/mainwindow.py | 5 | ||||
| -rw-r--r-- | src/leap/bitmask/logs/utils.py | 108 |
4 files changed, 116 insertions, 117 deletions
diff --git a/changes/bug-7222_run-background-zmq-subscriber b/changes/bug-7222_run-background-zmq-subscriber new file mode 100644 index 00000000..d074d005 --- /dev/null +++ b/changes/bug-7222_run-background-zmq-subscriber @@ -0,0 +1 @@ +- Run the zmq log subscriber in the background to avoid hitting the zmq's buffer limits. Closes #7222. diff --git a/src/leap/bitmask/gui/logwindow.py b/src/leap/bitmask/gui/logwindow.py index 123f14cc..718269c9 100644 --- a/src/leap/bitmask/gui/logwindow.py +++ b/src/leap/bitmask/gui/logwindow.py @@ -23,93 +23,15 @@ import cgi from PySide import QtCore, QtGui import logbook -from logbook.queues import ZeroMQSubscriber from ui_loggerwindow import Ui_LoggerWindow -from leap.bitmask.logs import LOG_FORMAT -from leap.bitmask.logs.utils import get_logger +from leap.bitmask.logs.utils import get_logger, LOG_CONTROLLER from leap.bitmask.util.constants import PASTEBIN_API_DEV_KEY from leap.bitmask.util import pastebin logger = get_logger() -# log history global variable used to store received logs through different -# opened instances of this window -_LOGS_HISTORY = [] - - -class QtLogHandler(logbook.Handler, logbook.StringFormatterHandlerMixin): - """ - Custom log handler which emits a log record with the message properly - formatted using a Qt Signal. - """ - - class _QtSignaler(QtCore.QObject): - """ - inline class used to hold the `new_log` Signal, if this is used - directly in the outside class it fails due how PySide works. - - This is the message we get if not use this method: - TypeError: Error when calling the metaclass bases - metaclass conflict: the metaclass of a derived class must be a - (non-strict) subclass of the metaclasses of all its bases - - """ - new_log = QtCore.Signal(object) - - def emit(self, data): - """ - emit the `new_log` Signal with the given `data` parameter. - - :param data: the data to emit along with the signal. - :type data: object - """ - # WARNING: the new-style connection does NOT work because PySide - # translates the emit method to self.emit, and that collides with - # the emit method for logging.Handler - # self.new_log.emit(log_item) - QtCore.QObject.emit(self, QtCore.SIGNAL('new_log(PyObject)'), data) - - def __init__(self, level=logbook.NOTSET, format_string=None, - encoding=None, filter=None, bubble=False): - - logbook.Handler.__init__(self, level, filter, bubble) - logbook.StringFormatterHandlerMixin.__init__(self, format_string) - - self.qt = self._QtSignaler() - - def __enter__(self): - return logbook.Handler.__enter__(self) - - def __exit__(self, exc_type, exc_value, tb): - return logbook.Handler.__exit__(self, exc_type, exc_value, tb) - - def emit(self, record): - """ - Emit the specified logging record using a Qt Signal. - Also add it to the history in order to be able to access it later. - - :param record: the record to emit - :type record: logbook.LogRecord - """ - global _LOGS_HISTORY - record.msg = self.format(record) - # NOTE: not optimal approach, we may want to look at - # bisect.insort with a custom approach to use key or - # http://code.activestate.com/recipes/577197-sortedcollection/ - # Sort logs on arrival, logs transmitted over zmq may arrive unsorted. - _LOGS_HISTORY.append(record) - _LOGS_HISTORY = sorted(_LOGS_HISTORY, key=lambda r: r.time) - - # XXX: emitting the record on arrival does not allow us to sort here so - # in the GUI the logs may arrive with with some time sort problem. - # We should implement a sort-on-arrive for the log window. - # Maybe we should switch to a tablewidget item that sort automatically - # by timestamp. - # As a user workaround you can close/open the log window - self.qt.emit(record) - class LoggerWindow(QtGui.QDialog): """ @@ -147,19 +69,8 @@ class LoggerWindow(QtGui.QDialog): self._set_logs_to_display() - self._my_handler = QtLogHandler(format_string=LOG_FORMAT) - self._my_handler.qt.new_log.connect(self._add_log_line) - + LOG_CONTROLLER.new_log.connect(self._add_log_line) self._load_history() - self._connect_to_logbook() - - def _connect_to_logbook(self): - """ - Run in the background the log receiver. - """ - subscriber = ZeroMQSubscriber('tcp://127.0.0.1:5000', multi=True) - self._logbook_controller = subscriber.dispatch_in_background( - self._my_handler) def _add_log_line(self, log): """ @@ -201,7 +112,7 @@ class LoggerWindow(QtGui.QDialog): self._set_logs_to_display() self.ui.txtLogHistory.clear() current_history = [] - for record in _LOGS_HISTORY: + for record in LOG_CONTROLLER.get_logs(): self._add_log_line(record) current_history.append(record.msg) @@ -334,27 +245,3 @@ class LoggerWindow(QtGui.QDialog): self._paste_thread = QtCore.QThread() self._paste_thread.run = lambda: do_pastebin() self._paste_thread.start() - - def closeEvent(self, e): - """ - Disconnect logger on close. - """ - self._disconnect_logger() - e.accept() - - def reject(self): - """ - Disconnect logger on reject. - """ - self._disconnect_logger() - QtGui.QDialog.reject(self) - - def _disconnect_logger(self): - """ - Stop the background thread that receives messages through zmq, also - close the subscriber socket. - This allows us to re-create the subscriber when we reopen this window - without getting an error at trying to connect twice to the zmq port. - """ - self._logbook_controller.stop() - self._logbook_controller.subscriber.close() diff --git a/src/leap/bitmask/gui/mainwindow.py b/src/leap/bitmask/gui/mainwindow.py index a2cf7bca..9f6c77cd 100644 --- a/src/leap/bitmask/gui/mainwindow.py +++ b/src/leap/bitmask/gui/mainwindow.py @@ -33,7 +33,7 @@ from leap.bitmask import __version_hash__ as VERSION_HASH from leap.bitmask.backend.leapbackend import ERROR_KEY, PASSED_KEY from leap.bitmask.config import flags -from leap.bitmask.logs.utils import get_logger +from leap.bitmask.logs.utils import get_logger, LOG_CONTROLLER from leap.bitmask.gui.advanced_key_management import AdvancedKeyManagement from leap.bitmask.gui.eip_status import EIPStatusWidget @@ -740,6 +740,8 @@ class MainWindow(QtGui.QMainWindow, SignalTracker): self._show_hide_unsupported_services() + LOG_CONTROLLER.start_logbook_subscriber() + # XXX - HACK, kind of... # With the 1ms QTimer.singleShot call we schedule the call right after # other signals waiting for the qt reactor to take control. @@ -1707,6 +1709,7 @@ class MainWindow(QtGui.QMainWindow, SignalTracker): self._leap_signaler.stop() + LOG_CONTROLLER.stop_logbook_subscriber() self._backend.stop() time.sleep(0.05) # give the thread a little time to finish. diff --git a/src/leap/bitmask/logs/utils.py b/src/leap/bitmask/logs/utils.py index 87d33876..f0e820b2 100644 --- a/src/leap/bitmask/logs/utils.py +++ b/src/leap/bitmask/logs/utils.py @@ -30,8 +30,11 @@ from leap.bitmask.platform_init import IS_WIN from leap.bitmask.util import get_path_prefix from leap.common.files import mkdir_p +from PySide import QtCore + import logbook from logbook.more import ColorizedStderrHandler +from logbook.queues import ZeroMQSubscriber # NOTE: make sure that the folder exists, the logger is created before saving @@ -107,3 +110,108 @@ def replace_stdout_stderr_with_logging(logger=None): # Replace twisted's logger to use our custom output. from twisted.python import log log.startLogging(sys.stdout) + + +class QtLogHandler(logbook.Handler, logbook.StringFormatterHandlerMixin): + """ + Custom log handler which emits a log record with the message properly + formatted using a Qt Signal. + """ + + class _QtSignaler(QtCore.QObject): + """ + inline class used to hold the `new_log` Signal, if this is used + directly in the outside class it fails due how PySide works. + + This is the message we get if not use this method: + TypeError: Error when calling the metaclass bases + metaclass conflict: the metaclass of a derived class must be a + (non-strict) subclass of the metaclasses of all its bases + + """ + new_log = QtCore.Signal(object) + + def emit(self, data): + """ + emit the `new_log` Signal with the given `data` parameter. + + :param data: the data to emit along with the signal. + :type data: object + """ + # WARNING: the new-style connection does NOT work because PySide + # translates the emit method to self.emit, and that collides with + # the emit method for logging.Handler + # self.new_log.emit(log_item) + QtCore.QObject.emit(self, QtCore.SIGNAL('new_log(PyObject)'), data) + + def __init__(self, level=logbook.NOTSET, format_string=None, + encoding=None, filter=None, bubble=False): + + logbook.Handler.__init__(self, level, filter, bubble) + logbook.StringFormatterHandlerMixin.__init__(self, format_string) + + self.qt = self._QtSignaler() + self.logs = [] + + def __enter__(self): + return logbook.Handler.__enter__(self) + + def __exit__(self, exc_type, exc_value, tb): + return logbook.Handler.__exit__(self, exc_type, exc_value, tb) + + def emit(self, record): + """ + Emit the specified logging record using a Qt Signal. + Also add it to the history in order to be able to access it later. + + :param record: the record to emit + :type record: logbook.LogRecord + """ + global _LOGS_HISTORY + record.msg = self.format(record) + # NOTE: not optimal approach, we may want to look at + # bisect.insort with a custom approach to use key or + # http://code.activestate.com/recipes/577197-sortedcollection/ + # Sort logs on arrival, logs transmitted over zmq may arrive unsorted. + self.logs.append(record) + self.logs = sorted(self.logs, key=lambda r: r.time) + + # XXX: emitting the record on arrival does not allow us to sort here so + # in the GUI the logs may arrive with with some time sort problem. + # We should implement a sort-on-arrive for the log window. + # Maybe we should switch to a tablewidget item that sort automatically + # by timestamp. + # As a user workaround you can close/open the log window + self.qt.emit(record) + + +class _LogController(object): + def __init__(self): + self._qt_handler = QtLogHandler(format_string=LOG_FORMAT) + self.new_log = self._qt_handler.qt.new_log + + def start_logbook_subscriber(self): + """ + Run in the background the log receiver. + """ + subscriber = ZeroMQSubscriber('tcp://127.0.0.1:5000', multi=True) + self._logbook_controller = subscriber.dispatch_in_background( + self._qt_handler) + + def stop_logbook_subscriber(self): + """ + Stop the background thread that receives messages through zmq, also + close the subscriber socket. + This allows us to re-create the subscriber when we reopen this window + without getting an error at trying to connect twice to the zmq port. + """ + self._logbook_controller.stop() + self._logbook_controller.subscriber.close() + + def get_logs(self): + return self._qt_handler.logs + +# use a global variable to store received logs through different opened +# instances of the log window as well as to containing the logbook background +# handle. +LOG_CONTROLLER = _LogController() |