May 2015 - tor-commits - lists.torproject.org

[nyx/master] Move log_file_path() to util
by atagar＠torproject.org 05 May '15

05 May '15

commit 095dc9cceb57c5c7649b594023fdad6505a17ac0 Author: Damian Johnson <atagar(a)torproject.org> Date: Mon Apr 27 09:29:36 2015 -0700 Move log_file_path() to util Small function that's been just begging to go into the util for a while now. --- nyx/log_panel.py | 29 ++++++++++------------------- nyx/util/log.py | 18 ++++++++++++++++++ 2 files changed, 28 insertions(+), 19 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index 5016e09..f250084 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -21,7 +21,7 @@ import nyx.popups from nyx import __version__ from nyx.util import join, panel, tor_controller, ui_tools -from nyx.util.log import TOR_RUNLEVELS, LogGroup, LogEntry, read_tor_log, condense_runlevels, days_since +from nyx.util.log import TOR_RUNLEVELS, LogGroup, LogEntry, read_tor_log, condense_runlevels, days_since, log_file_path ENTRY_INDENT = 2 # spaces an entry's message is indented after the first line @@ -48,7 +48,6 @@ CONFIG = conf.config_dict('nyx', { 'features.log.regex': [], 'cache.log_panel.size': 1000, 'msg.misc.event_types': '', - 'tor.chroot': '', 'attr.log_color': {}, }, conf_handler) @@ -71,14 +70,6 @@ NYX_LOGGER = log.LogBuffer(log.Runlevel.DEBUG, yield_records = True) stem_logger.addHandler(NYX_LOGGER) -def log_file_path(): - for log_entry in tor_controller().get_conf('Log', [], True): - entry_comp = log_entry.split() # looking for an entry like: notice file /var/log/tor/notices.log - - if entry_comp[1] == 'file': - return CONFIG['tor.chroot'] + entry_comp[2] - - class LogPanel(panel.Panel, threading.Thread): """ Listens for and displays tor, nyx, and stem events. This can prepopulate @@ -115,7 +106,7 @@ class LogPanel(panel.Panel, threading.Thread): self.regex_filter = None # filter for presented log events (no filtering if None) self.last_content_height = 0 # height of the rendered content when last drawn - self.log_file = None # file log messages are saved to (skipped if None) + self._log_file = None # file log messages are saved to (skipped if None) self.scroll = 0 self.set_pause_attr('_msg_log') @@ -142,7 +133,7 @@ class LogPanel(panel.Panel, threading.Thread): set_runlevels = list(set.intersection(set(self.logged_events), set(list(log.Runlevel)))) read_limit = CONFIG['features.log.prepopulateReadLimit'] - logging_location = log_file_path() + logging_location = log_file_path(tor_controller()) if logging_location: try: @@ -188,14 +179,14 @@ class LogPanel(panel.Panel, threading.Thread): if not os.path.exists(base_dir): os.makedirs(base_dir) - self.log_file = open(log_path, 'a') + self._log_file = open(log_path, 'a') log.notice('nyx %s opening log file (%s)' % (__version__, log_path)) except IOError as exc: log.error('Unable to write to log file: %s' % exc.strerror) - self.log_file = None + self._log_file = None except OSError as exc: log.error('Unable to write to log file: %s' % exc) - self.log_file = None + self._log_file = None def set_duplicate_visability(self, is_visible): """ @@ -747,13 +738,13 @@ class LogPanel(panel.Panel, threading.Thread): # note event in the log file if we're saving them - if self.log_file: + if self._log_file: try: - self.log_file.write(event.display_message + '\n') - self.log_file.flush() + self._log_file.write(event.display_message + '\n') + self._log_file.flush() except IOError as exc: log.error('Unable to write to log file: %s' % exc.strerror) - self.log_file = None + self._log_file = None with self.vals_lock: self._msg_log.add(event) diff --git a/nyx/util/log.py b/nyx/util/log.py index 9a40411..4df50c0 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -20,6 +20,7 @@ except ImportError: TOR_RUNLEVELS = ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR'] TIMEZONE_OFFSET = time.altzone if time.localtime()[8] else time.timezone +CONFIG = stem.util.conf.config_dict('nyx', {'tor.chroot': ''}) def days_since(timestamp): @@ -34,6 +35,23 @@ def days_since(timestamp): return int((timestamp - TIMEZONE_OFFSET) / 86400) +def log_file_path(controller): + """ + Provides the path where tor's log file resides, if one exists. + + :params stem.control.Controller controller: tor controller connection + + :returns: **str** with the absolute path of our log file, or **None** if one + doesn't exist + """ + + for log_entry in controller.get_conf('Log', [], True): + entry_comp = log_entry.split() # looking for an entry like: notice file /var/log/tor/notices.log + + if entry_comp[1] == 'file': + return CONFIG['tor.chroot'] + entry_comp[2] + + @lru_cache() def condense_runlevels(*events): """

1 0

[nyx/master] Register stem/nyx events from before curses starts
by atagar＠torproject.org 05 May '15

05 May '15

commit 59b6dabb2ce64684069a1a9fa796a586302acb23 Author: Damian Johnson <atagar(a)torproject.org> Date: Mon Apr 27 09:07:42 2015 -0700 Register stem/nyx events from before curses starts Recording events from when the log panel is imported, rather than after curses starts (which misses a lot of potentially interesting events). --- nyx/log_panel.py | 121 +++++++++++++++++++++++++----------------------------- nyx/util/log.py | 2 +- 2 files changed, 57 insertions(+), 66 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index fe75e18..3bfa739 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -8,7 +8,6 @@ import re import os import time import curses -import logging import threading import stem @@ -64,6 +63,13 @@ CONTENT_HEIGHT_REDRAW_THRESHOLD = 3 MAX_REGEX_FILTERS = 5 +# Log buffer so we start collecting stem/nyx events when imported. This is used +# to make our LogPanel when curses initializes. + +stem_logger = stem.util.log.get_logger() +NYX_LOGGER = log.LogBuffer(log.Runlevel.DEBUG, yield_records = True) +stem_logger.addHandler(NYX_LOGGER) + def log_file_path(): for log_entry in tor_controller().get_conf('Log', [], True): @@ -73,7 +79,7 @@ def log_file_path(): return CONFIG['tor.chroot'] + entry_comp[2] -class LogPanel(panel.Panel, threading.Thread, logging.Handler): +class LogPanel(panel.Panel, threading.Thread): """ Listens for and displays tor, nyx, and stem events. This can prepopulate from tor's log file if it exists. @@ -81,13 +87,6 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): def __init__(self, stdscr, logged_events): panel.Panel.__init__(self, stdscr, 'log', 0) - logging.Handler.__init__(self, level = log.logging_level(log.DEBUG)) - - self.setFormatter(logging.Formatter( - fmt = '%(asctime)s [%(levelname)s] %(message)s', - datefmt = '%m/%d/%Y %H:%M:%S'), - ) - threading.Thread.__init__(self) self.setDaemon(True) @@ -155,6 +154,13 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): except ValueError as exc: log.info(str(exc)) + # stop logging to NYX_LOGGER, adding its event backlog and future ones + + for event in NYX_LOGGER: + self._register_nyx_event(event) + + NYX_LOGGER.emit = self._register_nyx_event + # leaving last_content_height as being too low causes initialization problems self.last_content_height = len(self._msg_log) @@ -191,15 +197,6 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): log.error('Unable to write to log file: %s' % exc) self.log_file = None - stem_logger = log.get_logger() - stem_logger.addHandler(self) - - def emit(self, record): - if record.levelname == 'WARNING': - record.levelname = 'WARN' - - self.register_event(LogEntry(int(record.created), 'NYX_%s' % record.levelname, record.msg)) - def set_duplicate_visability(self, is_visible): """ Sets if duplicate log entries are collaped or expanded. @@ -212,51 +209,6 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): nyx_config = conf.get_config('nyx') nyx_config.set('features.log.showDuplicateEntries', str(is_visible)) - def register_tor_event(self, event): - """ - Translates a stem.response.event.Event instance into a LogEvent, and calls - register_event(). - """ - - msg = ' '.join(str(event).split(' ')[1:]) - - if isinstance(event, stem.response.events.BandwidthEvent): - msg = 'READ: %i, WRITTEN: %i' % (event.read, event.written) - elif isinstance(event, stem.response.events.LogEvent): - msg = event.message - - self.register_event(LogEntry(event.arrived_at, event.type, msg)) - - def register_event(self, event): - """ - Notes event and redraws log. If paused it's held in a temporary buffer. - - Arguments: - event - LogEntry for the event that occurred - """ - - if event.type not in self.logged_events: - return - - # note event in the log file if we're saving them - - if self.log_file: - try: - self.log_file.write(event.display_message + '\n') - self.log_file.flush() - except IOError as exc: - log.error('Unable to write to log file: %s' % exc.strerror) - self.log_file = None - - with self.vals_lock: - self._msg_log.add(event.timestamp, event.type, event.message) - - # notifies the display that it has new content - - if not self.regex_filter or self.regex_filter.search(event.display_message): - with self._cond: - self._cond.notifyAll() - def set_logged_events(self, event_types): """ Sets the event types recognized by the panel. @@ -761,14 +713,53 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): tor_events.update(set(nyx.arguments.missing_event_types())) controller = tor_controller() - controller.remove_event_listener(self.register_tor_event) + controller.remove_event_listener(self._register_tor_event) for event_type in list(tor_events): try: - controller.add_event_listener(self.register_tor_event, event_type) + controller.add_event_listener(self._register_tor_event, event_type) except stem.ProtocolError: tor_events.remove(event_type) # provides back the input set minus events we failed to set return sorted(tor_events.union(nyx_events)) + + def _register_tor_event(self, event): + msg = ' '.join(str(event).split(' ')[1:]) + + if isinstance(event, stem.response.events.BandwidthEvent): + msg = 'READ: %i, WRITTEN: %i' % (event.read, event.written) + elif isinstance(event, stem.response.events.LogEvent): + msg = event.message + + self._register_event(LogEntry(event.arrived_at, event.type, msg)) + + def _register_nyx_event(self, record): + if record.levelname == 'WARNING': + record.levelname = 'WARN' + + self._register_event(LogEntry(int(record.created), 'NYX_%s' % record.levelname, record.msg)) + + def _register_event(self, event): + if event.type not in self.logged_events: + return + + # note event in the log file if we're saving them + + if self.log_file: + try: + self.log_file.write(event.display_message + '\n') + self.log_file.flush() + except IOError as exc: + log.error('Unable to write to log file: %s' % exc.strerror) + self.log_file = None + + with self.vals_lock: + self._msg_log.add(event.timestamp, event.type, event.message) + + # notifies the display that it has new content + + if not self.regex_filter or self.regex_filter.search(event.display_message): + with self._cond: + self._cond.notifyAll() diff --git a/nyx/util/log.py b/nyx/util/log.py index 42c7ed5..279a390 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -39,7 +39,7 @@ def condense_runlevels(*events): """ Provides runlevel events with condensed. For example... - >>> condense_runlevels(['DEBUG', 'NOTICE', 'WARN', 'ERR', 'NYX_NOTICE', 'NYX_WARN', 'NYX_ERR', 'BW']) + >>> condense_runlevels('DEBUG', 'NOTICE', 'WARN', 'ERR', 'NYX_NOTICE', 'NYX_WARN', 'NYX_ERR', 'BW') ['TOR/NYX NOTICE-ERROR', 'DEBUG', 'BW'] :param list events: event types to be condensed

1 0

[nyx/master] Fix menu's 'exit' option
by atagar＠torproject.org 05 May '15

05 May '15

commit 594e96c389d05a81f658f766fe2c88bab1e763f8 Author: Damian Johnson <atagar(a)torproject.org> Date: Thu Apr 30 08:29:04 2015 -0700 Fix menu's 'exit' option Earlier change that dropped the quit method broke our menu, causing nyx to crash with the following when you bring it up... Traceback (most recent call last): File "./run_nyx", line 60, in <module> main() File "./run_nyx", line 17, in main nyx.starter.main() File "/home/atagar/Desktop/nyx/stem/util/conf.py", line 288, in wrapped return func(*args, config = config, **kwargs) File "/home/atagar/Desktop/nyx/nyx/starter.py", line 91, in main curses.wrapper(nyx.controller.start_nyx) File "/usr/lib/python2.7/curses/wrapper.py", line 43, in wrapper return func(stdscr, *args, **kwds) File "/home/atagar/Desktop/nyx/nyx/controller.py", line 590, in start_nyx nyx.menu.menu.show_menu() File "/home/atagar/Desktop/nyx/nyx/menu/menu.py", line 90, in show_menu menu = nyx.menu.actions.make_menu() File "/home/atagar/Desktop/nyx/nyx/menu/actions.py", line 31, in make_menu base_menu.add(make_actions_menu()) File "/home/atagar/Desktop/nyx/nyx/menu/actions.py", line 81, in make_actions_menu actions_menu.add(nyx.menu.item.MenuItem('Exit', control.quit)) AttributeError: Controller instance has no attribute 'quit' --- nyx/controller.py | 6 +++++- nyx/log_panel.py | 6 +----- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/nyx/controller.py b/nyx/controller.py index 6225038..77b2037 100644 --- a/nyx/controller.py +++ b/nyx/controller.py @@ -208,6 +208,7 @@ class Controller: page_panels - list of pages, each being a list of the panels on it """ + self.quit_signal = False self._screen = stdscr self._sticky_panels = sticky_panels self._page_panels = page_panels @@ -465,6 +466,9 @@ class Controller: return data_dir + def quit(self): + self.quit_signal = True + def heartbeat_check(is_unresponsive): """ @@ -558,7 +562,7 @@ def start_nyx(stdscr): override_key = None # uses this rather than waiting on user input is_unresponsive = False # flag for heartbeat responsiveness check - while True: + while not control.quit_signal: display_panels = control.get_display_panels() is_unresponsive = heartbeat_check(is_unresponsive) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index e1465ab..4a7e6de 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -369,9 +369,7 @@ class LogPanel(panel.Panel, threading.Thread): # does all activity under a curses lock to prevent redraws when adding # new filters - panel.CURSES_LOCK.acquire() - - try: + with CURSES_LOCK: selection = nyx.popups.show_menu('Log Filter:', options, old_selection) # applies new setting @@ -383,8 +381,6 @@ class LogPanel(panel.Panel, threading.Thread): self.show_filter_prompt() elif selection != -1: self.make_filter_selection(self.filter_options[selection - 1]) - finally: - panel.CURSES_LOCK.release() if len(self.filter_options) > MAX_REGEX_FILTERS: del self.filter_options[MAX_REGEX_FILTERS:]

1 0

[nyx/master] Don't clear log when re-attaching to tor
by atagar＠torproject.org 05 May '15

05 May '15

commit faa6dd144d254e201b547e86341be7dbc44d1d34 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Apr 26 22:21:15 2015 -0700 Don't clear log when re-attaching to tor Idea was to ensure logs concerned the tor instance we're attached to, but not sure this is actually desirable. When attaching to a restarted tor instance no reason to clear the nyx log panel. --- nyx/log_panel.py | 63 ++++++++++++++++++++---------------------------------- 1 file changed, 23 insertions(+), 40 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index 3e83de5..fe75e18 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -137,7 +137,23 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): self._last_logged_events = [] - self.reprepopulate_events() + # fetches past tor events from log file, if available + + if CONFIG['features.log.prepopulate']: + set_runlevels = list(set.intersection(set(self.logged_events), set(list(log.Runlevel)))) + read_limit = CONFIG['features.log.prepopulateReadLimit'] + + logging_location = log_file_path() + + if logging_location: + try: + for entry in reversed(list(read_tor_log(logging_location, read_limit))): + if entry.type in set_runlevels: + self._msg_log.add(entry.timestamp, entry.type, entry.message) + except IOError as exc: + log.info('Unable to read log located at %s: %s' % (logging_location, exc)) + except ValueError as exc: + log.info(str(exc)) # leaving last_content_height as being too low causes initialization problems @@ -146,7 +162,12 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): # adds listeners for tor and stem events controller = tor_controller() - controller.add_status_listener(self._reset_listener) + + def reset_listener(controller, event_type, _): + if event_type == State.CLOSED: + log.notice('Tor control port closed') + + controller.add_status_listener(reset_listener) # opens log file if we'll be saving entries @@ -179,34 +200,6 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): self.register_event(LogEntry(int(record.created), 'NYX_%s' % record.levelname, record.msg)) - def reprepopulate_events(self): - """ - Clears the event log and repopulates it from the nyx and tor backlogs. - """ - - with self.vals_lock: - # clears the event log - - self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) - - # fetches past tor events from log file, if available - - if CONFIG['features.log.prepopulate']: - set_runlevels = list(set.intersection(set(self.logged_events), set(list(log.Runlevel)))) - read_limit = CONFIG['features.log.prepopulateReadLimit'] - - logging_location = log_file_path() - - if logging_location: - try: - for entry in reversed(list(read_tor_log(logging_location, read_limit))): - if entry.type in set_runlevels: - self._msg_log.add(entry.timestamp, entry.type, entry.message) - except IOError as exc: - log.info('Unable to read log located at %s: %s' % (logging_location, exc)) - except ValueError as exc: - log.info(str(exc)) - def set_duplicate_visability(self, is_visible): """ Sets if duplicate log entries are collaped or expanded. @@ -779,13 +772,3 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): # provides back the input set minus events we failed to set return sorted(tor_events.union(nyx_events)) - - def _reset_listener(self, controller, event_type, _): - # if we're attaching to a new tor instance then clears the log and - # prepopulates it with the content belonging to this instance - - if event_type == State.INIT: - self.reprepopulate_events() - self.redraw(True) - elif event_type == State.CLOSED: - log.notice('Tor control port closed')

1 0

[nyx/master] Move tor event configuration to util
by atagar＠torproject.org 05 May '15

05 May '15

commit 895c6a5d13e09c235d7446307f01d8771d11ff1d Author: Damian Johnson <atagar(a)torproject.org> Date: Sat May 2 13:48:39 2015 -0700 Move tor event configuration to util Move listen_for_events() to util, and drop another largely unused helper. --- nyx/log_panel.py | 100 +++++++++++------------------------------------------- nyx/util/log.py | 36 ++++++++++++++++++++ 2 files changed, 56 insertions(+), 80 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index 2840c86..fe3e39e 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -18,7 +18,7 @@ import nyx.arguments import nyx.popups from nyx.util import join, panel, tor_controller, ui_tools -from nyx.util.log import TOR_RUNLEVELS, LogFileOutput, LogGroup, LogEntry, LogFilters, read_tor_log, condense_runlevels, days_since, log_file_path +from nyx.util.log import LogFileOutput, LogGroup, LogEntry, LogFilters, read_tor_log, condense_runlevels, listen_for_events, days_since, log_file_path ENTRY_INDENT = 2 # spaces an entry's message is indented after the first line @@ -74,22 +74,16 @@ class LogPanel(panel.Panel, threading.Thread): threading.Thread.__init__(self) self.setDaemon(True) + self._logged_event_types = listen_for_events(self._register_tor_event, logged_events) + self._logged_events = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) + self._log_file = LogFileOutput(CONFIG['features.log_file']) self._filter = LogFilters(initial_filters = CONFIG['features.log.regex']) - self.logged_events = [] # needs to be set before we receive any events - - # restricts the input to the set of events we can listen to, and - # configures the controller to liten to them - - self.logged_events = self.set_event_listening(logged_events) + self.set_pause_attr('_logged_events') self.last_content_height = 0 # height of the rendered content when last drawn - self._log_file = LogFileOutput(CONFIG['features.log_file']) self.scroll = 0 - self.set_pause_attr('_msg_log') - self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) - self._last_update = -1 # time the content was last revised self._halt = False # terminates thread if true self._cond = threading.Condition() # used for pausing/resuming the thread @@ -108,8 +102,8 @@ class LogPanel(panel.Panel, threading.Thread): if log_location: try: for entry in reversed(list(read_tor_log(log_location, CONFIG['features.log.prepopulateReadLimit']))): - if entry.type in self.logged_events: - self._msg_log.add(entry) + if entry.type in self._logged_event_types: + self._logged_events.add(entry) except IOError as exc: log.info('Unable to read log located at %s: %s' % (log_location, exc)) except ValueError as exc: @@ -124,7 +118,7 @@ class LogPanel(panel.Panel, threading.Thread): # leaving last_content_height as being too low causes initialization problems - self.last_content_height = len(self._msg_log) + self.last_content_height = len(self._logged_events) def set_duplicate_visability(self, is_visible): """ @@ -138,25 +132,6 @@ class LogPanel(panel.Panel, threading.Thread): nyx_config = conf.get_config('nyx') nyx_config.set('features.log.showDuplicateEntries', str(is_visible)) - def set_logged_events(self, event_types): - """ - Sets the event types recognized by the panel. - - Arguments: - event_types - event types to be logged - """ - - if event_types == self.logged_events: - return - - with self.vals_lock: - # configures the controller to listen for these tor events, and provides - # back a subset without anything we're failing to listen to - - set_types = self.set_event_listening(event_types) - self.logged_events = set_types - self.redraw(True) - def get_filter(self): """ Provides our currently selected regex filter. @@ -200,9 +175,13 @@ class LogPanel(panel.Panel, threading.Thread): if user_input: user_input = user_input.replace(' ', '') # strips spaces + event_types = nyx.arguments.expand_events(user_input) try: - self.set_logged_events(nyx.arguments.expand_events(user_input)) + if event_types != self._logged_event_types: + with self.vals_lock: + self._logged_event_types = listen_for_events(self._register_tor_event, event_types) + self.redraw(True) except ValueError as exc: nyx.popups.show_msg('Invalid flags: %s' % str(exc), 2) finally: @@ -228,7 +207,7 @@ class LogPanel(panel.Panel, threading.Thread): """ with self.vals_lock: - self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) + self._logged_events = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) self.redraw(True) def save_snapshot(self, path): @@ -257,7 +236,7 @@ class LogPanel(panel.Panel, threading.Thread): with self.vals_lock: try: - for entry in reversed(self._msg_log): + for entry in reversed(self._logged_events): is_visible = self._filter.match(entry.display_message) if is_visible: @@ -332,7 +311,7 @@ class LogPanel(panel.Panel, threading.Thread): contain up to two lines. Starts with newest entries. """ - event_log = self.get_attr('_msg_log') + event_log = self.get_attr('_logged_events') with self.vals_lock: self._last_logged_events, self._last_update = event_log, time.time() @@ -341,7 +320,7 @@ class LogPanel(panel.Panel, threading.Thread): # draws the top label if self.is_title_visible(): - comp = list(condense_runlevels(*self.logged_events)) + comp = list(condense_runlevels(*self._logged_event_types)) if self._filter.selection(): comp.append('filter: %s' % self._filter.selection()) @@ -515,10 +494,6 @@ class LogPanel(panel.Panel, threading.Thread): log.debug('redrawing the log panel with the corrected content height (%s)' % force_redraw_reason) self.redraw(True) - def redraw(self, force_redraw=False, block=False): - # determines if the content needs to be redrawn or not - panel.Panel.redraw(self, force_redraw, block) - def run(self): """ Redraws the display, coalescing updates if events are rapidly logged (for @@ -535,7 +510,7 @@ class LogPanel(panel.Panel, threading.Thread): sleep_time = 0 - if (self._msg_log == self._last_logged_events and last_day == current_day) or self.is_paused(): + if (self._logged_events == self._last_logged_events and last_day == current_day) or self.is_paused(): sleep_time = 5 elif time_since_reset < max_log_update_rate: sleep_time = max(0.05, max_log_update_rate - time_since_reset) @@ -562,41 +537,6 @@ class LogPanel(panel.Panel, threading.Thread): self._halt = True self._cond.notifyAll() - def set_event_listening(self, events): - """ - Configures the events Tor listens for, filtering non-tor events from what we - request from the controller. This returns a sorted list of the events we - successfully set. - - Arguments: - events - event types to attempt to set - """ - - events = set(events) # drops duplicates - - # accounts for runlevel naming difference - - tor_events = events.intersection(set(nyx.arguments.TOR_EVENT_TYPES.values())) - nyx_events = events.intersection(set(['NYX_%s' % runlevel for runlevel in TOR_RUNLEVELS])) - - # adds events unrecognized by nyx if we're listening to the 'UNKNOWN' type - - if 'UNKNOWN' in events: - tor_events.update(set(nyx.arguments.missing_event_types())) - - controller = tor_controller() - controller.remove_event_listener(self._register_tor_event) - - for event_type in list(tor_events): - try: - controller.add_event_listener(self._register_tor_event, event_type) - except stem.ProtocolError: - tor_events.remove(event_type) - - # provides back the input set minus events we failed to set - - return sorted(tor_events.union(nyx_events)) - def _register_tor_event(self, event): msg = ' '.join(str(event).split(' ')[1:]) @@ -614,11 +554,11 @@ class LogPanel(panel.Panel, threading.Thread): self._register_event(LogEntry(int(record.created), 'NYX_%s' % record.levelname, record.msg)) def _register_event(self, event): - if event.type not in self.logged_events: + if event.type not in self._logged_event_types: return with self.vals_lock: - self._msg_log.add(event) + self._logged_events.add(event) self._log_file.write(event.display_message) # notifies the display that it has new content diff --git a/nyx/util/log.py b/nyx/util/log.py index 64abc4f..1371bb8 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -126,6 +126,42 @@ def condense_runlevels(*events): return result + events +def listen_for_events(listener, events): + """ + Configures tor to notify a function of these event types. If tor is + configured to notify this listener then the old listener is replaced. + + :param function listener: listener to be notified + :param list events: event types to attempt to set + + :returns: **list** of event types we're successfully now listening to + """ + + import nyx.arguments + events = set(events) # drops duplicates + + # accounts for runlevel naming difference + + tor_events = events.intersection(set(nyx.arguments.TOR_EVENT_TYPES.values())) + nyx_events = events.intersection(set(['NYX_%s' % runlevel for runlevel in TOR_RUNLEVELS])) + + # adds events unrecognized by nyx if we're listening to the 'UNKNOWN' type + + if 'UNKNOWN' in events: + tor_events.update(set(nyx.arguments.missing_event_types())) + + controller = nyx.util.tor_controller() + controller.remove_event_listener(listener) + + for event_type in list(tor_events): + try: + controller.add_event_listener(listener, event_type) + except stem.ProtocolError: + tor_events.remove(event_type) + + return sorted(tor_events.union(nyx_events)) + + @lru_cache() def _common_log_messages(): """

1 0

[nyx/master] Revise days_since() to behave more intuitively
by atagar＠torproject.org 05 May '15

05 May '15

commit 6a582784233e4db9e6b5a5035f3b5eebbdf908ce Author: Damian Johnson <atagar(a)torproject.org> Date: Mon May 4 20:39:16 2015 -0700 Revise days_since() to behave more intuitively We only used days_since() to figure out if one day was the same as another, so didn't really care what the value actually was. Changing it to be in reference to today at midnight so zero means today, one means yesterday, etc. --- nyx/util/log.py | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/nyx/util/log.py b/nyx/util/log.py index 1371bb8..f224789 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -24,20 +24,25 @@ except ImportError: from stem.util.lru_cache import lru_cache TOR_RUNLEVELS = ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR'] -TIMEZONE_OFFSET = time.altzone if time.localtime()[8] else time.timezone CONFIG = stem.util.conf.config_dict('nyx', {'tor.chroot': ''}) def days_since(timestamp): """ Provides the number of days since a given unix timestamp, by local time. + Daybreaks are rolled over at midnight. For instance, 5pm today would report + zero, and 5pm yesterday would report one. :param int timestamp: unix timestamp to provide time since :reutrns: **int** with the number of days since this event """ - return int((timestamp - TIMEZONE_OFFSET) / 86400) + # unix timestamp for today at midnight + + midnight = time.mktime(datetime.datetime.today().date().timetuple()) + + return int((midnight - timestamp) / 86400) def log_file_path(controller):

1 0

[nyx/master] Revise log panel's filter handling
by atagar＠torproject.org 05 May '15

05 May '15

commit c8341ae3fee5330e3fd013aaa054ef3a59736a92 Author: Damian Johnson <atagar(a)torproject.org> Date: Fri May 1 09:14:31 2015 -0700 Revise log panel's filter handling Adding a small LogFilters class which allows us to drop quite a bit. --- nyx/log_panel.py | 110 ++++++++------------------------------------------- nyx/menu/actions.py | 6 ++- nyx/util/log.py | 49 +++++++++++++++++++++++ 3 files changed, 69 insertions(+), 96 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index 4a7e6de..2840c86 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -4,7 +4,6 @@ for. This provides prepopulation from the log file and supports filtering by regular expressions. """ -import re import os import time import curses @@ -19,7 +18,7 @@ import nyx.arguments import nyx.popups from nyx.util import join, panel, tor_controller, ui_tools -from nyx.util.log import TOR_RUNLEVELS, LogFileOutput, LogGroup, LogEntry, read_tor_log, condense_runlevels, days_since, log_file_path +from nyx.util.log import TOR_RUNLEVELS, LogFileOutput, LogGroup, LogEntry, LogFilters, read_tor_log, condense_runlevels, days_since, log_file_path ENTRY_INDENT = 2 # spaces an entry's message is indented after the first line @@ -56,10 +55,6 @@ CONFIG = conf.config_dict('nyx', { CONTENT_HEIGHT_REDRAW_THRESHOLD = 3 -# maximum number of regex filters we'll remember - -MAX_REGEX_FILTERS = 5 - # Log buffer so we start collecting stem/nyx events when imported. This is used # to make our LogPanel when curses initializes. @@ -79,21 +74,7 @@ class LogPanel(panel.Panel, threading.Thread): threading.Thread.__init__(self) self.setDaemon(True) - # regex filters the user has defined - - self.filter_options = [] - - for filter in CONFIG['features.log.regex']: - # checks if we can't have more filters - - if len(self.filter_options) >= MAX_REGEX_FILTERS: - break - - try: - re.compile(filter) - self.filter_options.append(filter) - except re.error as exc: - log.notice('Invalid regular expression pattern (%s): %s' % (exc, filter)) + self._filter = LogFilters(initial_filters = CONFIG['features.log.regex']) self.logged_events = [] # needs to be set before we receive any events @@ -102,7 +83,6 @@ class LogPanel(panel.Panel, threading.Thread): self.logged_events = self.set_event_listening(logged_events) - self.regex_filter = None # filter for presented log events (no filtering if None) self.last_content_height = 0 # height of the rendered content when last drawn self._log_file = LogFileOutput(CONFIG['features.log_file']) self.scroll = 0 @@ -113,11 +93,6 @@ class LogPanel(panel.Panel, threading.Thread): self._last_update = -1 # time the content was last revised self._halt = False # terminates thread if true self._cond = threading.Condition() # used for pausing/resuming the thread - - # restricts concurrent write access to attributes used to draw the display - # and pausing: - # msg_log, logged_events, regex_filter, scroll - self.vals_lock = threading.RLock() # cached parameters (invalidated if arguments for them change) @@ -187,49 +162,7 @@ class LogPanel(panel.Panel, threading.Thread): Provides our currently selected regex filter. """ - return self.filter_options[0] if self.regex_filter else None - - def set_filter(self, log_filter): - """ - Filters log entries according to the given regular expression. - - Arguments: - log_filter - regular expression used to determine which messages are - shown, None if no filter should be applied - """ - - if log_filter == self.regex_filter: - return - - with self.vals_lock: - self.regex_filter = log_filter - self.redraw(True) - - def make_filter_selection(self, selected_option): - """ - Makes the given filter selection, applying it to the log and reorganizing - our filter selection. - - Arguments: - selected_option - regex filter we've already added, None if no filter - should be applied - """ - - if selected_option: - try: - self.set_filter(re.compile(selected_option)) - - # move selection to top - - self.filter_options.remove(selected_option) - self.filter_options.insert(0, selected_option) - except re.error as exc: - # shouldn't happen since we've already checked validity - - log.warn("Invalid regular expression ('%s': %s) - removing from listing" % (selected_option, exc)) - self.filter_options.remove(selected_option) - else: - self.set_filter(None) + return self._filter def show_filter_prompt(self): """ @@ -239,15 +172,7 @@ class LogPanel(panel.Panel, threading.Thread): regex_input = nyx.popups.input_prompt('Regular expression: ') if regex_input: - try: - self.set_filter(re.compile(regex_input)) - - if regex_input in self.filter_options: - self.filter_options.remove(regex_input) - - self.filter_options.insert(0, regex_input) - except re.error as exc: - nyx.popups.show_msg('Unable to compile expression: %s' % exc, 2) + self._filter.select(regex_input) def show_event_selection_prompt(self): """ @@ -333,7 +258,7 @@ class LogPanel(panel.Panel, threading.Thread): with self.vals_lock: try: for entry in reversed(self._msg_log): - is_visible = not self.regex_filter or self.regex_filter.search(entry.display_message) + is_visible = self._filter.match(entry.display_message) if is_visible: snapshot_file.write(entry.display_message + '\n') @@ -363,27 +288,24 @@ class LogPanel(panel.Panel, threading.Thread): # Provides menu to pick regular expression filters or adding new ones: # for syntax see: http://docs.python.org/library/re.html#regular-expression-syntax - options = ['None'] + self.filter_options + ['New...'] - old_selection = 0 if not self.regex_filter else 1 + options = ['None'] + self._filter.latest_selections() + ['New...'] + old_selection = 0 if not self._filter.selection() else 1 # does all activity under a curses lock to prevent redraws when adding # new filters - with CURSES_LOCK: + with panel.CURSES_LOCK: selection = nyx.popups.show_menu('Log Filter:', options, old_selection) # applies new setting if selection == 0: - self.set_filter(None) + self._filter.select(None) elif selection == len(options) - 1: # selected 'New...' option - prompt user to input regular expression self.show_filter_prompt() elif selection != -1: - self.make_filter_selection(self.filter_options[selection - 1]) - - if len(self.filter_options) > MAX_REGEX_FILTERS: - del self.filter_options[MAX_REGEX_FILTERS:] + self._filter.select(self._filter.latest_selections()[selection - 1]) elif key.match('e'): self.show_event_selection_prompt() elif key.match('a'): @@ -399,7 +321,7 @@ class LogPanel(panel.Panel, threading.Thread): ('down arrow', 'scroll log down a line', None), ('a', 'save snapshot of the log', None), ('e', 'change logged events', None), - ('f', 'log regex filter', 'enabled' if self.regex_filter else 'disabled'), + ('f', 'log regex filter', 'enabled' if self._filter.selection() else 'disabled'), ('u', 'duplicate log entries', 'visible' if CONFIG['features.log.showDuplicateEntries'] else 'hidden'), ('c', 'clear event log', None), ] @@ -419,10 +341,10 @@ class LogPanel(panel.Panel, threading.Thread): # draws the top label if self.is_title_visible(): - comp = condense_runlevels(*self.logged_events) + comp = list(condense_runlevels(*self.logged_events)) - if self.regex_filter: - comp.append('filter: %s' % self.regex_filter) + if self._filter.selection(): + comp.append('filter: %s' % self._filter.selection()) comp_str = join(comp, ', ', width - 10) title = 'Events (%s):' % comp_str if comp_str else 'Events:' @@ -470,7 +392,7 @@ class LogPanel(panel.Panel, threading.Thread): while deduplicated_log: entry, duplicate_count = deduplicated_log.pop(0) - if self.regex_filter and not self.regex_filter.search(entry.display_message): + if not self._filter.match(entry.display_message): continue # filter doesn't match log message - skip # checks if we should be showing a divider with the date @@ -701,6 +623,6 @@ class LogPanel(panel.Panel, threading.Thread): # notifies the display that it has new content - if not self.regex_filter or self.regex_filter.search(event.display_message): + if self._filter.match(event.display_message): with self._cond: self._cond.notifyAll() diff --git a/nyx/menu/actions.py b/nyx/menu/actions.py index 03b7b77..25b7c14 100644 --- a/nyx/menu/actions.py +++ b/nyx/menu/actions.py @@ -213,12 +213,14 @@ def make_log_menu(log_panel): # filter submenu + log_filter = log_panel.get_filter() + filter_menu = nyx.menu.item.Submenu('Filter') - filter_group = nyx.menu.item.SelectionGroup(log_panel.make_filter_selection, log_panel.get_filter()) + filter_group = nyx.menu.item.SelectionGroup(log_filter.select, log_filter.selection()) filter_menu.add(nyx.menu.item.SelectionMenuItem('None', filter_group, None)) - for option in log_panel.filter_options: + for option in log_filter.latest_selections(): filter_menu.add(nyx.menu.item.SelectionMenuItem(option, filter_group, option)) filter_menu.add(nyx.menu.item.MenuItem('New...', log_panel.show_filter_prompt)) diff --git a/nyx/util/log.py b/nyx/util/log.py index e188cb4..64abc4f 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -3,8 +3,10 @@ Logging utilities, primiarily short aliases for logging a message at various runlevels. """ +import collections import datetime import os +import re import time import threading @@ -307,6 +309,53 @@ class LogFileOutput(object): self._file = None +class LogFilters(object): + """ + Regular expression filtering for log output. This is thread safe and tracks + the latest selections. + """ + + def __init__(self, initial_filters = None, max_filters = 5): + self._max_filters = max_filters + self._selected = None + self._past_filters = collections.OrderedDict() + self._lock = threading.RLock() + + if initial_filters: + for regex in initial_filters: + self.select(regex) + + self.select(None) + + def select(self, regex): + with self._lock: + if regex is None: + self._selected = None + return + + if regex in self._past_filters: + del self._past_filters[regex] + + try: + self._past_filters[regex] = re.compile(regex) + self._selected = regex + + if len(self._past_filters) > self._max_filters: + self._past_filters.popitem(False) + except re.error as exc: + notice('Invalid regular expression pattern (%s): %s' % (exc, regex)) + + def selection(self): + return self._selected + + def latest_selections(self): + return list(reversed(self._past_filters.keys())) + + def match(self, message): + regex_filter = self._past_filters.get(self._selected) + return not regex_filter or bool(regex_filter.search(message)) + + def trace(msg, **attr): _log(stem.util.log.TRACE, msg, **attr)

1 0

[nyx/master] Overhaul daybreak handling
by atagar＠torproject.org 05 May '15

05 May '15

commit 85f98793c90f13b5bdc9a8922ae40380614373f4 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Apr 26 11:38:36 2015 -0700 Overhaul daybreak handling I never liked our old approach for grouping entries by day. Oh, and it was inefficient as hell. Replacing it with simpler and more performant grouping. --- nyx/log_panel.py | 159 +++++++++-------------------- nyx/util/log.py | 33 +++++- test/util/log/data/daybreak_deduplication | 37 +++++++ test/util/log/log_group.py | 61 ++++++++++- 4 files changed, 176 insertions(+), 114 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index f61d9c6..2038a69 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -22,10 +22,7 @@ import nyx.popups from nyx import __version__ from nyx.util import panel, tor_controller, ui_tools -from nyx.util.log import LogGroup, LogEntry, read_tor_log - -DAYBREAK_EVENT = 'DAYBREAK' # special event for marking when the date changes -TIMEZONE_OFFSET = time.altzone if time.localtime()[8] else time.timezone +from nyx.util.log import LogGroup, LogEntry, read_tor_log, days_since ENTRY_INDENT = 2 # spaces an entry's message is indented after the first line @@ -65,32 +62,11 @@ DUPLICATE_MSG = ' [%i duplicate%s hidden]' CONTENT_HEIGHT_REDRAW_THRESHOLD = 3 -# cached values and the arguments that generated it for the get_daybreaks and -# get_duplicates functions - -CACHED_DAYBREAKS_ARGUMENTS = (None, None) # events, current day -CACHED_DAYBREAKS_RESULT = None - # maximum number of regex filters we'll remember MAX_REGEX_FILTERS = 5 -def days_since(timestamp = None): - """ - Provides the number of days since the epoch converted to local time (rounded - down). - - Arguments: - timestamp - unix timestamp to convert, current time if undefined - """ - - if timestamp is None: - timestamp = time.time() - - return int((timestamp - TIMEZONE_OFFSET) / 86400) - - def log_file_path(): for log_entry in tor_controller().get_conf('Log', [], True): entry_comp = log_entry.split() # looking for an entry like: notice file /var/log/tor/notices.log @@ -99,48 +75,6 @@ def log_file_path(): return CONFIG['tor.chroot'] + entry_comp[2] -def get_daybreaks(events, ignore_time_for_cache = False): - """ - Provides the input events back with special 'DAYBREAK_EVENT' markers inserted - whenever the date changed between log entries (or since the most recent - event). The timestamp matches the beginning of the day for the following - entry. - - Arguments: - events - chronologically ordered listing of events - ignore_time_for_cache - skips taking the day into consideration for providing - cached results if true - """ - - global CACHED_DAYBREAKS_ARGUMENTS, CACHED_DAYBREAKS_RESULT - - if not events: - return [] - - new_listing = [] - current_day = days_since() - last_day = current_day - - if CACHED_DAYBREAKS_ARGUMENTS[0] == events and \ - (ignore_time_for_cache or CACHED_DAYBREAKS_ARGUMENTS[1] == current_day): - return list(CACHED_DAYBREAKS_RESULT) - - for entry in events: - event_day = days_since(entry.timestamp) - - if event_day != last_day: - marker_timestamp = (event_day * 86400) + TIMEZONE_OFFSET - new_listing.append(LogEntry(marker_timestamp, DAYBREAK_EVENT, '')) - - new_listing.append(entry) - last_day = event_day - - CACHED_DAYBREAKS_ARGUMENTS = (list(events), current_day) - CACHED_DAYBREAKS_RESULT = list(new_listing) - - return new_listing - - class LogPanel(panel.Panel, threading.Thread, logging.Handler): """ Listens for and displays tor, nyx, and stem events. This can prepopulate @@ -188,7 +122,7 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): self.scroll = 0 self.set_pause_attr('_msg_log') - self._msg_log = LogGroup(CONFIG['cache.log_panel.size']) + self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) self._last_update = -1 # time the content was last revised self._halt = False # terminates thread if true @@ -260,7 +194,7 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): with self.vals_lock: # clears the event log - self._msg_log = LogGroup(CONFIG['cache.log_panel.size']) + self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) # fetches past tor events from log file, if available @@ -477,7 +411,7 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): """ with self.vals_lock: - self._msg_log = LogGroup(CONFIG['cache.log_panel.size']) + self._msg_log = LogGroup(CONFIG['cache.log_panel.size'], group_by_day = CONFIG['features.log.showDateDividers']) self.redraw(True) def save_snapshot(self, path): @@ -635,6 +569,7 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): # determines if we have the minimum width to show date dividers show_daybreaks = width - divider_indent >= 3 + last_day = deduplicated_log[0][0].days_since() while deduplicated_log: entry, duplicate_count = deduplicated_log.pop(0) @@ -644,7 +579,7 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): # checks if we should be showing a divider with the date - if entry.type == DAYBREAK_EVENT: + if last_day != entry.days_since(): # bottom of the divider if seen_first_date_divider: @@ -669,57 +604,59 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): seen_first_date_divider = True line_count += 1 - else: - # entry contents to be displayed, tuples of the form: - # (msg, formatting, includeLinebreak) - display_queue = [] + # entry contents to be displayed, tuples of the form: + # (msg, formatting, includeLinebreak) - msg_comp = entry.display_message.split('\n') + display_queue = [] - for i in range(len(msg_comp)): - font = curses.A_BOLD if 'ERR' in entry.type else curses.A_NORMAL # emphasizes ERR messages - display_queue.append((msg_comp[i].strip(), (font, CONFIG['attr.log_color'].get(entry.type, 'white')), i != len(msg_comp) - 1)) + msg_comp = entry.display_message.split('\n') - if duplicate_count: - plural_label = 's' if duplicate_count > 1 else '' - duplicate_msg = DUPLICATE_MSG % (duplicate_count, plural_label) - display_queue.append((duplicate_msg, duplicate_attr, False)) + for i in range(len(msg_comp)): + font = curses.A_BOLD if 'ERR' in entry.type else curses.A_NORMAL # emphasizes ERR messages + display_queue.append((msg_comp[i].strip(), (font, CONFIG['attr.log_color'].get(entry.type, 'white')), i != len(msg_comp) - 1)) - cursor_location, line_offset = msg_indent, 0 - max_entries_per_line = CONFIG['features.log.max_lines_per_entry'] + if duplicate_count: + plural_label = 's' if duplicate_count > 1 else '' + duplicate_msg = DUPLICATE_MSG % (duplicate_count, plural_label) + display_queue.append((duplicate_msg, duplicate_attr, False)) - while display_queue: - msg, format, include_break = display_queue.pop(0) - draw_line = line_count + line_offset + # TODO: a fix made line_offset unused, and probably broke max_entries_per_line... not sure if we care - if line_offset == max_entries_per_line: - break + cursor_location, line_offset = msg_indent, 0 + max_entries_per_line = CONFIG['features.log.max_lines_per_entry'] - max_msg_size = width - cursor_location - 1 + while display_queue: + msg, format, include_break = display_queue.pop(0) + draw_line = line_count + line_offset - if len(msg) > max_msg_size: - # message is too long - break it up - if line_offset == max_entries_per_line - 1: - msg = str_tools.crop(msg, max_msg_size) - else: - msg, remainder = str_tools.crop(msg, max_msg_size, 4, 4, str_tools.Ending.HYPHEN, True) - display_queue.insert(0, (remainder.strip(), format, include_break)) + if line_offset == max_entries_per_line: + break - include_break = True + max_msg_size = width - cursor_location - 1 + + if len(msg) > max_msg_size: + # message is too long - break it up + if line_offset == max_entries_per_line - 1: + msg = str_tools.crop(msg, max_msg_size) + else: + msg, remainder = str_tools.crop(msg, max_msg_size, 4, 4, str_tools.Ending.HYPHEN, True) + display_queue.insert(0, (remainder.strip(), format, include_break)) - if draw_line < height and draw_line >= 1: - if seen_first_date_divider and width - divider_indent >= 3 and show_daybreaks: - self.addch(draw_line, divider_indent, curses.ACS_VLINE, *divider_attr) - self.addch(draw_line, width - 1, curses.ACS_VLINE, *divider_attr) + include_break = True - self.addstr(draw_line, cursor_location, msg, *format) + if draw_line < height and draw_line >= 1: + if seen_first_date_divider and width - divider_indent >= 3 and show_daybreaks: + self.addch(draw_line, divider_indent, curses.ACS_VLINE, *divider_attr) + self.addch(draw_line, width - 1, curses.ACS_VLINE, *divider_attr) - cursor_location += len(msg) + self.addstr(draw_line, cursor_location, msg, *format) - if include_break or not display_queue: - line_offset += 1 - cursor_location = msg_indent + ENTRY_INDENT + cursor_location += len(msg) + + if include_break or not display_queue: + line_count += 1 + cursor_location = msg_indent + ENTRY_INDENT line_count += line_offset @@ -733,6 +670,8 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): line_count += 1 + last_day = entry.days_since() + # redraw the display if... # - last_content_height was off by too much # - we're off the bottom of the page @@ -769,10 +708,10 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler): responsive if additions are less frequent. """ - last_day = days_since() # used to determine if the date has changed + last_day = days_since(time.time()) # used to determine if the date has changed while not self._halt: - current_day = days_since() + current_day = days_since(time.time()) time_since_reset = time.time() - self._last_update max_log_update_rate = CONFIG['features.log.maxRefreshRate'] / 1000.0 diff --git a/nyx/util/log.py b/nyx/util/log.py index 545eb75..58126a7 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -19,6 +19,19 @@ except ImportError: from stem.util.lru_cache import lru_cache TOR_RUNLEVELS = ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR'] +TIMEZONE_OFFSET = time.altzone if time.localtime()[8] else time.timezone + + +def days_since(timestamp): + """ + Provides the number of days since a given unix timestamp, by local time. + + :param int timestamp: unix timestamp to provide time since + + :reutrns: **int** with the number of days since this event + """ + + return int((timestamp - TIMEZONE_OFFSET) / 86400) @lru_cache() @@ -47,19 +60,24 @@ class LogGroup(object): and supports deduplication. """ - def __init__(self, max_size): + def __init__(self, max_size, group_by_day = False): self._max_size = max_size + self._group_by_day = group_by_day self._entries = [] self._lock = threading.RLock() def add(self, timestamp, type, message): - entry = LogEntry(timestamp, type, message) + self.add_entry(LogEntry(timestamp, type, message)) + def add_entry(self, entry): with self._lock: duplicate = None + our_day = entry.days_since() for existing_entry in self._entries: - if entry.is_duplicate_of(existing_entry): + if self._group_by_day and our_day != existing_entry.days_since(): + break + elif entry.is_duplicate_of(existing_entry): duplicate = existing_entry break @@ -150,6 +168,15 @@ class LogEntry(object): return False + def days_since(self): + """ + Provides the number of days since this event, by local time. + + :reutrns: **int** with the number of days since this event + """ + + return days_since(self.timestamp) + def __eq__(self, other): if isinstance(other, LogEntry): return hash(self) == hash(other) diff --git a/test/util/log/data/daybreak_deduplication b/test/util/log/data/daybreak_deduplication new file mode 100644 index 0000000..1849ad3 --- /dev/null +++ b/test/util/log/data/daybreak_deduplication @@ -0,0 +1,37 @@ +Apr 24 19:50:42.000 [notice] Heartbeat: Tor's uptime is 12 days 0:00 hours, with 0 circuits open. I've sent 4.94 MB and received 130.17 MB. +Apr 24 19:50:42.000 [notice] Average packaged cell fullness: 65.101%. TLS write overhead: 11% +Apr 25 01:50:42.000 [notice] Heartbeat: Tor's uptime is 12 days 6:00 hours, with 0 circuits open. I've sent 5.00 MB and received 131.87 MB. +Apr 25 01:50:42.000 [notice] Average packaged cell fullness: 64.927%. TLS write overhead: 11% +Apr 25 07:50:42.000 [notice] Heartbeat: Tor's uptime is 12 days 12:00 hours, with 0 circuits open. I've sent 5.08 MB and received 134.19 MB. +Apr 25 07:50:42.000 [notice] Average packaged cell fullness: 64.587%. TLS write overhead: 11% +Apr 25 11:44:21.000 [notice] New control connection opened from 127.0.0.1. +Apr 25 11:44:33.000 [notice] Interrupt: exiting cleanly. +Apr 25 11:44:36.000 [notice] Tor 0.2.7.0-alpha-dev (git-63a90f2df4dcd7ff) opening log file. +Apr 25 11:44:36.492 [notice] Tor v0.2.7.0-alpha-dev (git-63a90f2df4dcd7ff) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4. +Apr 25 11:44:36.492 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning +Apr 25 11:44:36.492 [notice] This version is not a stable Tor release. Expect more bugs than usual. +Apr 25 11:44:36.525 [notice] Read configuration file "/home/atagar/.tor/torrc". +Apr 25 11:44:36.530 [notice] Opening Socks listener on 127.0.0.1:9050 +Apr 25 11:44:36.530 [notice] Opening Control listener on 127.0.0.1:9051 +Apr 25 11:44:36.000 [notice] Bootstrapped 0%: Starting +Apr 25 11:44:39.000 [notice] Bootstrapped 45%: Asking for relay descriptors +Apr 25 11:44:40.000 [notice] Bootstrapped 50%: Loading relay descriptors +Apr 25 11:44:47.000 [notice] Bootstrapped 55%: Loading relay descriptors +Apr 25 11:44:47.000 [notice] Bootstrapped 62%: Loading relay descriptors +Apr 25 11:44:48.000 [notice] Bootstrapped 72%: Loading relay descriptors +Apr 25 11:44:48.000 [notice] Bootstrapped 80%: Connecting to the Tor network +Apr 25 11:44:48.000 [notice] Bootstrapped 90%: Establishing a Tor circuit +Apr 25 11:44:49.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working. +Apr 25 11:44:49.000 [notice] Bootstrapped 100%: Done +Apr 25 11:45:03.000 [notice] New control connection opened from 127.0.0.1. +Apr 25 17:44:40.000 [notice] Heartbeat: Tor's uptime is 6:00 hours, with 0 circuits open. I've sent 539 kB and received 4.25 MB. +Apr 25 18:11:56.000 [notice] New control connection opened from 127.0.0.1. +Apr 25 18:52:47.000 [notice] New control connection opened from 127.0.0.1. +Apr 25 19:02:44.000 [notice] New control connection opened from 127.0.0.1. +Apr 25 23:44:40.000 [notice] Heartbeat: Tor's uptime is 12:00 hours, with 1 circuits open. I've sent 794 kB and received 7.32 MB. +Apr 26 05:44:40.000 [notice] Heartbeat: Tor's uptime is 18:00 hours, with 0 circuits open. I've sent 862 kB and received 9.05 MB. +Apr 26 10:16:38.000 [notice] New control connection opened from 127.0.0.1. +Apr 26 10:19:24.000 [notice] New control connection opened from 127.0.0.1. +Apr 26 10:21:31.000 [notice] New control connection opened from 127.0.0.1. +Apr 26 10:24:27.000 [notice] New control connection opened from 127.0.0.1. +Apr 26 10:24:46.000 [notice] New control connection opened from 127.0.0.1. diff --git a/test/util/log/log_group.py b/test/util/log/log_group.py index 732ee14..d1f1f46 100644 --- a/test/util/log/log_group.py +++ b/test/util/log/log_group.py @@ -1,6 +1,7 @@ +import os import unittest -from nyx.util.log import LogGroup, LogEntry +from nyx.util.log import LogGroup, LogEntry, read_tor_log class TestLogGroup(unittest.TestCase): @@ -85,3 +86,61 @@ class TestLogGroup(unittest.TestCase): self.assertEqual(None, group_items[0].duplicates) self.assertEqual(bootstrap_messages, [e.message for e in group_items[1].duplicates]) self.assertEqual([False, False, True, True, False], [e.is_duplicate for e in group_items]) + + def test_deduplication_with_daybreaks(self): + group = LogGroup(100, group_by_day = True) + test_log_path = os.path.join(os.path.dirname(__file__), 'data', 'daybreak_deduplication') + + for entry in reversed(list(read_tor_log(test_log_path))): + group.add_entry(entry) + + # Entries should consist of two days of results... + # + # Day 1: + # 10:24:27 [NOTICE] New control connection opened from 127.0.0.1. + # 10:21:31 [NOTICE] New control connection opened from 127.0.0.1. + # 10:19:24 [NOTICE] New control connection opened from 127.0.0.1. + # 10:16:38 [NOTICE] New control connection opened from 127.0.0.1. + # 10:16:38 [NOTICE] New control connection opened from 127.0.0.1. + # 05:44:40 [NOTICE] Heartbeat: Tor's uptime is 18:00 hours, with 0 circuits open. I've sent 862 kB and received 9.05 MB. + # + # Day 2: + # 23:44:40 [NOTICE] Heartbeat: Tor's uptime is 12:00 hours, with 1 circuits open. I've sent 794 kB and received 7.32 MB. + # 19:02:44 [NOTICE] New control connection opened from 127.0.0.1. + # 18:52:47 [NOTICE] New control connection opened from 127.0.0.1. + # 18:11:56 [NOTICE] New control connection opened from 127.0.0.1. + # 17:44:40 [NOTICE] Heartbeat: Tor's uptime is 6:00 hours, with 0 circuits open. I've sent 539 kB and received 4.25 MB. + # 11:45:03 [NOTICE] New control connection opened from 127.0.0.1. + # 11:44:49 [NOTICE] Bootstrapped 100%: Done + # ... etc... + + group_items = list(group) + + # First day + + self.assertEqual('New control connection opened from 127.0.0.1.', group_items[0].message) + self.assertEqual(5, len(group_items[0].duplicates)) + self.assertFalse(group_items[0].is_duplicate) + + for entry in group_items[1:5]: + self.assertEqual('New control connection opened from 127.0.0.1.', entry.message) + self.assertEqual(5, len(entry.duplicates)) + self.assertTrue(entry.is_duplicate) + + self.assertEqual("Heartbeat: Tor's uptime is 18:00 hours, with 0 circuits open. I've sent 862 kB and received 9.05 MB.", group_items[5].message) + self.assertEqual(None, group_items[5].duplicates) + self.assertFalse(group_items[5].is_duplicate) + + # Second day + + self.assertEqual("Heartbeat: Tor's uptime is 12:00 hours, with 1 circuits open. I've sent 794 kB and received 7.32 MB.", group_items[6].message) + self.assertEqual(2, len(group_items[6].duplicates)) + self.assertFalse(group_items[6].is_duplicate) + + self.assertEqual('New control connection opened from 127.0.0.1.', group_items[8].message) + self.assertEqual(4, len(group_items[8].duplicates)) + self.assertTrue(group_items[8].is_duplicate) + + self.assertEqual("Heartbeat: Tor's uptime is 6:00 hours, with 0 circuits open. I've sent 539 kB and received 4.25 MB.", group_items[10].message) + self.assertEqual(2, len(group_items[10].duplicates)) + self.assertTrue(group_items[10].is_duplicate)

1 0

[nyx/master] Have LogGroup's add() accept LogEntries
by atagar＠torproject.org 05 May '15

05 May '15

commit a1f6177e8c08e203bac584ad3dd0f2f1cf9500de Author: Damian Johnson <atagar(a)torproject.org> Date: Mon Apr 27 09:17:32 2015 -0700 Have LogGroup's add() accept LogEntries On reflection we always have a log entry on hand so lets just have the add method take that. The only thing that used the prior add() method was the tests. --- nyx/log_panel.py | 4 ++-- nyx/util/log.py | 5 +---- test/util/log/log_group.py | 42 +++++++++++++++++++++--------------------- 3 files changed, 24 insertions(+), 27 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index 3bfa739..5016e09 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -148,7 +148,7 @@ class LogPanel(panel.Panel, threading.Thread): try: for entry in reversed(list(read_tor_log(logging_location, read_limit))): if entry.type in set_runlevels: - self._msg_log.add(entry.timestamp, entry.type, entry.message) + self._msg_log.add(entry) except IOError as exc: log.info('Unable to read log located at %s: %s' % (logging_location, exc)) except ValueError as exc: @@ -756,7 +756,7 @@ class LogPanel(panel.Panel, threading.Thread): self.log_file = None with self.vals_lock: - self._msg_log.add(event.timestamp, event.type, event.message) + self._msg_log.add(event) # notifies the display that it has new content diff --git a/nyx/util/log.py b/nyx/util/log.py index 279a390..9a40411 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -135,10 +135,7 @@ class LogGroup(object): self._entries = [] self._lock = threading.RLock() - def add(self, timestamp, type, message): - self.add_entry(LogEntry(timestamp, type, message)) - - def add_entry(self, entry): + def add(self, entry): with self._lock: duplicate = None our_day = entry.days_since() diff --git a/test/util/log/log_group.py b/test/util/log/log_group.py index d1f1f46..f4716ca 100644 --- a/test/util/log/log_group.py +++ b/test/util/log/log_group.py @@ -9,41 +9,41 @@ class TestLogGroup(unittest.TestCase): group = LogGroup(5) self.assertEqual(0, len(group)) - group.add(1333738410, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"') + group.add(LogEntry(1333738410, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"')) self.assertEqual([LogEntry(1333738410, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"')], list(group)) self.assertEqual(1, len(group)) - group.add(1333738420, 'NYX_DEBUG', 'GETCONF MyFamily (runtime: 0.0007)') - group.add(1333738430, 'NOTICE', 'Bootstrapped 72%: Loading relay descriptors.') - group.add(1333738440, 'NOTICE', 'Bootstrapped 75%: Loading relay descriptors.') - group.add(1333738450, 'NOTICE', 'Bootstrapped 78%: Loading relay descriptors.') + group.add(LogEntry(1333738420, 'NYX_DEBUG', 'GETCONF MyFamily (runtime: 0.0007)')) + group.add(LogEntry(1333738430, 'NOTICE', 'Bootstrapped 72%: Loading relay descriptors.')) + group.add(LogEntry(1333738440, 'NOTICE', 'Bootstrapped 75%: Loading relay descriptors.')) + group.add(LogEntry(1333738450, 'NOTICE', 'Bootstrapped 78%: Loading relay descriptors.')) self.assertEqual(5, len(group)) # group should now be full, adding more entries pops others off - group.add(1333738460, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') + group.add(LogEntry(1333738460, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) self.assertFalse(LogEntry(1333738410, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"') in list(group)) self.assertEqual(5, len(group)) # try adding a bunch that will be deduplicated, and make sure we still maintain the size - group.add(1333738510, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738520, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738530, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738540, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738550, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738560, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') - group.add(1333738570, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') + group.add(LogEntry(1333738510, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738520, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738530, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738540, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738550, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738560, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) + group.add(LogEntry(1333738570, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) self.assertEqual([1333738570, 1333738560, 1333738550, 1333738540, 1333738530], [e.timestamp for e in group]) self.assertEqual(5, len(group)) def test_deduplication(self): group = LogGroup(5) - group.add(1333738410, 'NOTICE', 'Bootstrapped 72%: Loading relay descriptors.') - group.add(1333738420, 'NOTICE', 'Bootstrapped 75%: Loading relay descriptors.') - group.add(1333738430, 'NYX_DEBUG', 'GETCONF MyFamily (runtime: 0.0007)') - group.add(1333738440, 'NOTICE', 'Bootstrapped 78%: Loading relay descriptors.') - group.add(1333738450, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.') + group.add(LogEntry(1333738410, 'NOTICE', 'Bootstrapped 72%: Loading relay descriptors.')) + group.add(LogEntry(1333738420, 'NOTICE', 'Bootstrapped 75%: Loading relay descriptors.')) + group.add(LogEntry(1333738430, 'NYX_DEBUG', 'GETCONF MyFamily (runtime: 0.0007)')) + group.add(LogEntry(1333738440, 'NOTICE', 'Bootstrapped 78%: Loading relay descriptors.')) + group.add(LogEntry(1333738450, 'NOTICE', 'Bootstrapped 80%: Loading relay descriptors.')) self.assertEqual([1333738450, 1333738440, 1333738430, 1333738420, 1333738410], [e.timestamp for e in group]) bootstrap_messages = [ @@ -59,7 +59,7 @@ class TestLogGroup(unittest.TestCase): # add another duplicate message that pops the last - group.add(1333738460, 'NOTICE', 'Bootstrapped 90%: Loading relay descriptors.') + group.add(LogEntry(1333738460, 'NOTICE', 'Bootstrapped 90%: Loading relay descriptors.')) bootstrap_messages = [ 'Bootstrapped 90%: Loading relay descriptors.', @@ -74,7 +74,7 @@ class TestLogGroup(unittest.TestCase): # add another non-duplicate message that pops the last - group.add(1333738470, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"') + group.add(LogEntry(1333738470, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"')) bootstrap_messages = [ 'Bootstrapped 90%: Loading relay descriptors.', @@ -92,7 +92,7 @@ class TestLogGroup(unittest.TestCase): test_log_path = os.path.join(os.path.dirname(__file__), 'data', 'daybreak_deduplication') for entry in reversed(list(read_tor_log(test_log_path))): - group.add_entry(entry) + group.add(entry) # Entries should consist of two days of results... #

1 0

[nyx/master] Revise outputing logs to a file
by atagar＠torproject.org 05 May '15

05 May '15

commit 179a7dcd216661fa32a3ea300b9b1a7dd2c19cc7 Author: Damian Johnson <atagar(a)torproject.org> Date: Tue Apr 28 09:49:51 2015 -0700 Revise outputing logs to a file Moving this to its own simple class. Much nicer. --- nyx/log_panel.py | 38 +++----------------------------------- nyx/util/log.py | 35 +++++++++++++++++++++++++++++++++++ 2 files changed, 38 insertions(+), 35 deletions(-) diff --git a/nyx/log_panel.py b/nyx/log_panel.py index f250084..44a2b2a 100644 --- a/nyx/log_panel.py +++ b/nyx/log_panel.py @@ -19,9 +19,8 @@ from stem.util import conf, log, str_tools import nyx.arguments import nyx.popups -from nyx import __version__ from nyx.util import join, panel, tor_controller, ui_tools -from nyx.util.log import TOR_RUNLEVELS, LogGroup, LogEntry, read_tor_log, condense_runlevels, days_since, log_file_path +from nyx.util.log import TOR_RUNLEVELS, LogFileOutput, LogGroup, LogEntry, read_tor_log, condense_runlevels, days_since, log_file_path ENTRY_INDENT = 2 # spaces an entry's message is indented after the first line @@ -106,7 +105,7 @@ class LogPanel(panel.Panel, threading.Thread): self.regex_filter = None # filter for presented log events (no filtering if None) self.last_content_height = 0 # height of the rendered content when last drawn - self._log_file = None # file log messages are saved to (skipped if None) + self._log_file = LogFileOutput(CONFIG['features.log_file']) self.scroll = 0 self.set_pause_attr('_msg_log') @@ -166,28 +165,6 @@ class LogPanel(panel.Panel, threading.Thread): controller.add_status_listener(reset_listener) - # opens log file if we'll be saving entries - - if CONFIG['features.log_file']: - log_path = CONFIG['features.log_file'] - - try: - # make dir if the path doesn't already exist - - base_dir = os.path.dirname(log_path) - - if not os.path.exists(base_dir): - os.makedirs(base_dir) - - self._log_file = open(log_path, 'a') - log.notice('nyx %s opening log file (%s)' % (__version__, log_path)) - except IOError as exc: - log.error('Unable to write to log file: %s' % exc.strerror) - self._log_file = None - except OSError as exc: - log.error('Unable to write to log file: %s' % exc) - self._log_file = None - def set_duplicate_visability(self, is_visible): """ Sets if duplicate log entries are collaped or expanded. @@ -736,18 +713,9 @@ class LogPanel(panel.Panel, threading.Thread): if event.type not in self.logged_events: return - # note event in the log file if we're saving them - - if self._log_file: - try: - self._log_file.write(event.display_message + '\n') - self._log_file.flush() - except IOError as exc: - log.error('Unable to write to log file: %s' % exc.strerror) - self._log_file = None - with self.vals_lock: self._msg_log.add(event) + self._log_file.write(event.display_message) # notifies the display that it has new content diff --git a/nyx/util/log.py b/nyx/util/log.py index 4df50c0..a2e3820 100644 --- a/nyx/util/log.py +++ b/nyx/util/log.py @@ -3,6 +3,7 @@ Logging utilities, primiarily short aliases for logging a message at various runlevels. """ +import os import time import threading @@ -10,6 +11,7 @@ import stem.util.conf import stem.util.log import stem.util.system +import nyx import nyx.util try: @@ -271,6 +273,39 @@ class LogEntry(object): return hash(self.display_message) +class LogFileOutput(object): + """ + File where log messages we receive are written. If unable to do so then a + notification is logged and further write attempts are skipped. + """ + + def __init__(self, path): + self._file = None + + if path: + try: + path_dir = os.path.dirname(path) + + if not os.path.exists(path_dir): + os.makedirs(path_dir) + + self._file = open(path, 'a') + notice('nyx %s opening log file (%s)' % (nyx.__version__, path)) + except IOError as exc: + error('Unable to write to log file: %s' % exc.strerror) + except OSError as exc: + error('Unable to write to log file: %s' % exc) + + def write(self, msg): + if self._file: + try: + self._file.write(msg + '\n') + self._file.flush() + except IOError as exc: + error('Unable to write to log file: %s' % exc.strerror) + self._file = None + + def trace(msg, **attr): _log(stem.util.log.TRACE, msg, **attr)

1 0