[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
[tor-commits] [nyx/master] read_tor_log() for reading tor log files
commit b20b60df25a5f99f32b0f347173083883e6fb409
Author: Damian Johnson <atagar@xxxxxxxxxxxxxx>
Date: Mon Apr 6 15:41:50 2015 -0700
read_tor_log() for reading tor log files
Replacing get_log_file_entries() with a tested, simpler function. This is still
a lot grosser than I'd like, but not much I can do unless something happens
with #15607.
---
nyx/config/strings.cfg | 1 +
nyx/log_panel.py | 149 ++++-----------------------------
nyx/util/__init__.py | 9 +-
nyx/util/log.py | 77 +++++++++++++++++
run_tests.py | 5 +-
test/util/data/malformed_date | 21 +++++
test/util/data/malformed_line | 21 +++++
test/util/data/malformed_runlevel | 21 +++++
test/util/data/multiple_tor_instances | 33 ++++++++
test/util/data/tor_log | 21 +++++
test/util/read_tor_log.py | 59 +++++++++++++
11 files changed, 282 insertions(+), 135 deletions(-)
diff --git a/nyx/config/strings.cfg b/nyx/config/strings.cfg
index d1169b9..7660bfb 100644
--- a/nyx/config/strings.cfg
+++ b/nyx/config/strings.cfg
@@ -24,6 +24,7 @@ msg.panel.graphing.prepopulation_successful Bandwidth graph has information for
msg.panel.graphing.bw_event_cache_malformed Tor's 'GETINFO bw-event-cache' provided malformed output: {response}
msg.panel.header.fd_used_at_sixty_percent Tor's file descriptor usage is at {percentage}%.
msg.panel.header.fd_used_at_ninety_percent Tor's file descriptor usage is at {percentage}%. If you run out Tor will be unable to continue functioning.
+msg.panel.log.read_from_log_file Read {count} entries from tor's log file: {path} (read limit: {read_limit}, runtime: {runtime})
msg.setup.nyx_is_running_as_root Nyx is currently running with root permissions. This isn't a good idea, nor should it be necessary. Try starting nyx with "sudo -u {tor_user} nyx" instead.
msg.setup.chroot_doesnt_exist The chroot path set in your config ({path}) doesn't exist.
diff --git a/nyx/log_panel.py b/nyx/log_panel.py
index b314eaa..8650996 100644
--- a/nyx/log_panel.py
+++ b/nyx/log_panel.py
@@ -14,12 +14,13 @@ import threading
import stem
from stem.control import State
from stem.response import events
-from stem.util import conf, log, str_tools, system
+from stem.util import conf, log, str_tools
import nyx.arguments
import nyx.popups
from nyx import __version__
from nyx.util import panel, tor_controller, ui_tools
+from nyx.util.log import read_tor_log
RUNLEVEL_EVENT_COLOR = {
log.DEBUG: 'magenta',
@@ -124,136 +125,12 @@ def load_log_messages():
COMMON_LOG_MESSAGES[event_type] = messages
-def get_log_file_entries(runlevels, read_limit = None, add_limit = None):
- """
- Parses tor's log file for past events matching the given runlevels, providing
- a list of log entries (ordered newest to oldest). Limiting the number of read
- entries is suggested to avoid parsing everything from logs in the GB and TB
- range.
-
- Arguments:
- runlevels - event types (DEBUG - ERR) to be returned
- read_limit - max lines of the log file that'll be read (unlimited if None)
- add_limit - maximum entries to provide back (unlimited if None)
- """
-
- start_time = time.time()
-
- if not runlevels:
- return []
-
- # checks tor's configuration for the log file's location (if any exists)
-
- logging_types, logging_location = None, None
-
- for logging_entry in tor_controller().get_conf('Log', [], True):
- # looks for an entry like: notice file /var/log/tor/notices.log
-
- entry_comp = logging_entry.split()
+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':
- logging_types, logging_location = entry_comp[0], entry_comp[2]
- break
-
- if not logging_location:
- return []
-
- # includes the prefix for tor paths
-
- logging_location = CONFIG['tor.chroot'] + logging_location
-
- # if the runlevels argument is a superset of the log file then we can
- # limit the read contents to the add_limit
-
- runlevels = list(log.Runlevel)
- logging_types = logging_types.upper()
-
- if add_limit and (not read_limit or read_limit > add_limit):
- if '-' in logging_types:
- div_index = logging_types.find('-')
- start_index = runlevels.index(logging_types[:div_index])
- end_index = runlevels.index(logging_types[div_index + 1:])
- log_file_run_levels = runlevels[start_index:end_index + 1]
- else:
- start_index = runlevels.index(logging_types)
- log_file_run_levels = runlevels[start_index:]
-
- # checks if runlevels we're reporting are a superset of the file's contents
-
- is_file_subset = True
-
- for runlevel_type in log_file_run_levels:
- if runlevel_type not in runlevels:
- is_file_subset = False
- break
-
- if is_file_subset:
- read_limit = add_limit
-
- logged_events = []
- current_unix_time, current_local_time = time.time(), time.localtime()
-
- try:
- for line in system.tail(logging_location, read_limit):
- # entries look like:
- # Jul 15 18:29:48.806 [notice] Parsing GEOIP file.
-
- line_comp = line.split()
-
- # Checks that we have all the components we expect. This could happen if
- # we're either not parsing a tor log or in weird edge cases (like being
- # out of disk space)
-
- if len(line_comp) < 4:
- continue
-
- event_type = line_comp[3][1:-1].upper()
-
- if event_type in runlevels:
- # converts timestamp to unix time
-
- timestamp = ' '.join(line_comp[:3])
-
- # strips the decimal seconds
-
- if '.' in timestamp:
- timestamp = timestamp[:timestamp.find('.')]
-
- # Ignoring wday and yday since they aren't used.
- #
- # Pretend the year is 2012, because 2012 is a leap year, and parsing a
- # date with strptime fails if Feb 29th is passed without a year that's
- # actually a leap year. We can't just use the current year, because we
- # might be parsing old logs which didn't get rotated.
- #
- # https://trac.torproject.org/projects/tor/ticket/5265
-
- timestamp = '2012 ' + timestamp
- event_time_comp = list(time.strptime(timestamp, '%Y %b %d %H:%M:%S'))
- event_time_comp[8] = current_local_time.tm_isdst
- event_time = time.mktime(event_time_comp) # converts local to unix time
-
- # The above is gonna be wrong if the logs are for the previous year. If
- # the event's in the future then correct for this.
-
- if event_time > current_unix_time + 60:
- event_time_comp[0] -= 1
- event_time = time.mktime(event_time_comp)
-
- event_msg = ' '.join(line_comp[4:])
- logged_events.append(LogEntry(event_time, event_type, event_msg, RUNLEVEL_EVENT_COLOR[event_type]))
-
- if 'opening log file' in line:
- break # this entry marks the start of this tor instance
- except IOError:
- log.warn("Unable to read tor's log file: %s" % logging_location)
-
- if add_limit:
- logged_events = logged_events[:add_limit]
-
- log.info("Read %i entries from tor's log file: %s (read limit: %i, runtime: %0.3f)" % (len(logged_events), logging_location, read_limit, time.time() - start_time))
-
- return logged_events
+ return CONFIG['tor.chroot'] + entry_comp[2]
def get_daybreaks(events, ignore_time_for_cache = False):
@@ -571,10 +448,18 @@ class LogPanel(panel.Panel, threading.Thread, logging.Handler):
if CONFIG['features.log.prepopulate']:
set_runlevels = list(set.intersection(set(self.logged_events), set(list(log.Runlevel))))
read_limit = CONFIG['features.log.prepopulateReadLimit']
- add_limit = CONFIG['cache.log_panel.size']
- for entry in get_log_file_entries(set_runlevels, read_limit, add_limit):
- self.msg_log.append(entry)
+ logging_location = log_file_path()
+
+ if logging_location:
+ try:
+ for entry in read_tor_log(logging_location, read_limit):
+ if entry.runlevel in set_runlevels:
+ self.msg_log.append(LogEntry(entry.timestamp, entry.runlevel, entry.message, RUNLEVEL_EVENT_COLOR[entry.runlevel]))
+ 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))
# crops events that are either too old, or more numerous than the caching size
diff --git a/nyx/util/__init__.py b/nyx/util/__init__.py
index 0e07dfc..58e739c 100644
--- a/nyx/util/__init__.py
+++ b/nyx/util/__init__.py
@@ -17,11 +17,13 @@ import sys
import stem.connection
import stem.util.conf
+import stem.util.log
from nyx.util import log
TOR_CONTROLLER = None
BASE_DIR = os.path.sep.join(__file__.split(os.path.sep)[:-2])
+TESTING = False
try:
uses_settings = stem.util.conf.uses_settings('nyx', os.path.join(BASE_DIR, 'config'), lazy_load = False)
@@ -105,5 +107,10 @@ def msg(message, config, **attr):
try:
return config.get('msg.%s' % message).format(**attr)
except:
- log.notice('BUG: We attempted to use an undefined string resource (%s)' % message)
+ msg = 'BUG: We attempted to use an undefined string resource (%s)' % message
+
+ if TESTING:
+ raise ValueError(msg)
+
+ stem.util.log.notice(msg)
return ''
diff --git a/nyx/util/log.py b/nyx/util/log.py
index 05061b9..d2e2eff 100644
--- a/nyx/util/log.py
+++ b/nyx/util/log.py
@@ -3,10 +3,22 @@ Logging utilities, primiarily short aliases for logging a message at various
runlevels.
"""
+import collections
+import time
+
import stem.util.log
+import stem.util.system
import nyx.util
+LogEntry = collections.namedtuple('LogEntry', [
+ 'timestamp',
+ 'runlevel',
+ 'message',
+])
+
+TOR_RUNLEVELS = ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR']
+
def trace(msg, **attr):
_log(stem.util.log.TRACE, msg, **attr)
@@ -42,3 +54,68 @@ def _log(runlevel, message, **attr):
"""
stem.util.log.log(runlevel, nyx.util.msg(message, **attr))
+
+
+def read_tor_log(path, read_limit = None):
+ """
+ Provides logging messages from a tor log file, from newest to oldest.
+ LogEntry this provides have three attributes...
+
+ * **timestamp** (int)
+ * **runlevel** (str)
+ * **message** (str)
+
+ **Note:** The 'timestamp' has a hardcoded year of 2012 due to :trac:`15607`.
+
+ :param str path: logging location to read from
+ :param int read_limit: maximum number of lines to read from the file
+
+ :returns: **iterator** for **LogEntry** for the file's contents
+
+ :raises:
+ * **ValueError** if the log file has unrecognized content
+ * **IOError** if unable to read the file
+ """
+
+ start_time = time.time()
+ count, isdst = 0, time.localtime().tm_isdst
+
+ for line in stem.util.system.tail(path, read_limit):
+ # entries look like:
+ # Jul 15 18:29:48.806 [notice] Parsing GEOIP file.
+
+ line_comp = line.split()
+
+ # Checks that we have all the components we expect. This could happen if
+ # we're either not parsing a tor log or in weird edge cases (like being
+ # out of disk space).
+
+ if len(line_comp) < 4:
+ raise ValueError("Log located at %s has a line that doesn't match the format we expect: %s" % (path, line))
+ elif len(line_comp[3]) < 3 or line_comp[3][1:-1].upper() not in TOR_RUNLEVELS:
+ raise ValueError('Log located at %s has an unrecognized runlevel: %s' % (path, line_comp[3]))
+
+ runlevel = line_comp[3][1:-1].upper()
+ msg = ' '.join(line_comp[4:])
+
+ # Pretending the year is 2012 because 2012 is a leap year. We don't know
+ # the actual year (#15607) so picking something else risks strptime failing
+ # when it reads Feb 29th (#5265).
+
+ try:
+ timestamp_str = '2012 ' + ' '.join(line_comp[:3])
+ timestamp_str = timestamp_str.split('.', 1)[0] # drop fractional seconds
+ timestamp_comp = list(time.strptime(timestamp_str, '%Y %b %d %H:%M:%S'))
+ timestamp_comp[8] = isdst
+
+ timestamp = int(time.mktime(timestamp_comp)) # converts local to unix time
+ except ValueError:
+ raise ValueError("Log located at %s has a timestamp we don't recognize: %s" % (path, ' '.join(line_comp[:3])))
+
+ count += 1
+ yield LogEntry(timestamp, runlevel, msg)
+
+ if 'opening log file' in msg:
+ break # this entry marks the start of this tor instance
+
+ info('panel.log.read_from_log_file', count = count, path = path, read_limit = read_limit if read_limit else 'none', runtime = '%0.3f' % (time.time() - start_time))
diff --git a/run_tests.py b/run_tests.py
index d239393..17e879d 100755
--- a/run_tests.py
+++ b/run_tests.py
@@ -13,7 +13,7 @@ import unittest
import stem.util.conf
import stem.util.test_tools
-from nyx.util import uses_settings
+import nyx.util
NYX_BASE = os.path.dirname(__file__)
@@ -25,8 +25,9 @@ SRC_PATHS = [os.path.join(NYX_BASE, path) for path in (
)]
-@uses_settings
+@xxxxxxxxxxxxxxxxxxxxxx
def main():
+ nyx.util.TESTING = True
test_config = stem.util.conf.get_config('test')
test_config.load(os.path.join(NYX_BASE, 'test', 'settings.cfg'))
diff --git a/test/util/data/empty_file b/test/util/data/empty_file
new file mode 100644
index 0000000..e69de29
diff --git a/test/util/data/malformed_date b/test/util/data/malformed_date
new file mode 100644
index 0000000..712149d
--- /dev/null
+++ b/test/util/data/malformed_date
@@ -0,0 +1,21 @@
+Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
+Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:03:39.832 [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 06 11:03:39.833 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:03:39.833 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:03:39.838 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:03:39.838 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:03:39.000 [notice] Bootstrapped 0%: Starting
+Apr 06 11:03:42.000 [notice] Bootstrapped 45%: Asking for relay descriptors
+Apr 06 11:03:43.000 [notice] Bootstrapped 50%: Loading relay descriptors
+Apr 06 11:03:49.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:03:51.000 [notice] Bootstrapped 55%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 63%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 69%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 74%: Loading relay descriptors
+Apr 06 11:03:52.000 [notice] Bootstrapped 80%: Connecting to the Tor network
+Zed 06 11:03:52.000 [notice] Bootstrapped 90%: Establishing a Tor circuit
+Apr 06 11:03:53.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
+Apr 06 11:03:53.000 [notice] Bootstrapped 100%: Done
+Apr 06 11:03:55.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:53:46.000 [notice] Interrupt: exiting cleanly.
diff --git a/test/util/data/malformed_line b/test/util/data/malformed_line
new file mode 100644
index 0000000..ac9a367
--- /dev/null
+++ b/test/util/data/malformed_line
@@ -0,0 +1,21 @@
+Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
+Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:03:39.832 [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 06 11:03:39.833 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:03:39.833 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:03:39.838 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:03:39.838 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:03:39.000 [notice] Bootstrapped 0%: Starting
+Apr 06 11:03:42.000 [notice] Bootstrapped 45%: Asking for relay descriptors
+Apr 06 11:03:43.000 [notice] Bootstrapped 50%: Loading relay descriptors
+Apr 06 11:03:49.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:03:51.000 [notice] Bootstrapped 55%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 63%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 69%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 74%: Loading relay descriptors
+Apr 06 11:03:52.000 [notice] Bootstrapped 80%: Connecting to the Tor network
+Apr 06 11:03:52.000 [notice] Bootstrapped 90%: Establishing a Tor circuit
+Apr 06 11:03:53.000
+Apr 06 11:03:53.000 [notice] Bootstrapped 100%: Done
+Apr 06 11:03:55.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:53:46.000 [notice] Interrupt: exiting cleanly.
diff --git a/test/util/data/malformed_runlevel b/test/util/data/malformed_runlevel
new file mode 100644
index 0000000..dd8810b
--- /dev/null
+++ b/test/util/data/malformed_runlevel
@@ -0,0 +1,21 @@
+Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
+Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:03:39.832 [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 06 11:03:39.833 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:03:39.833 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:03:39.838 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:03:39.838 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:03:39.000 [notice] Bootstrapped 0%: Starting
+Apr 06 11:03:42.000 [notice] Bootstrapped 45%: Asking for relay descriptors
+Apr 06 11:03:43.000 [notice] Bootstrapped 50%: Loading relay descriptors
+Apr 06 11:03:49.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:03:51.000 [notice] Bootstrapped 55%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 63%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 69%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 74%: Loading relay descriptors
+Apr 06 11:03:52.000 [notice] Bootstrapped 80%: Connecting to the Tor network
+Apr 06 11:03:52.000 [unrecognized] Bootstrapped 90%: Establishing a Tor circuit
+Apr 06 11:03:53.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
+Apr 06 11:03:53.000 [notice] Bootstrapped 100%: Done
+Apr 06 11:03:55.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:53:46.000 [notice] Interrupt: exiting cleanly.
diff --git a/test/util/data/multiple_tor_instances b/test/util/data/multiple_tor_instances
new file mode 100644
index 0000000..1793ce5
--- /dev/null
+++ b/test/util/data/multiple_tor_instances
@@ -0,0 +1,33 @@
+Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
+Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:03:39.832 [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 06 11:03:39.833 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:03:39.833 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:03:39.838 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:03:39.838 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:03:39.000 [notice] Bootstrapped 0%: Starting
+Apr 06 11:03:42.000 [notice] Bootstrapped 45%: Asking for relay descriptors
+Apr 06 11:03:43.000 [notice] Bootstrapped 50%: Loading relay descriptors
+Apr 06 11:03:49.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:03:51.000 [notice] Bootstrapped 55%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 63%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 69%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 74%: Loading relay descriptors
+Apr 06 11:03:52.000 [notice] Bootstrapped 80%: Connecting to the Tor network
+Apr 06 11:03:52.000 [notice] Bootstrapped 90%: Establishing a Tor circuit
+Apr 06 11:03:53.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
+Apr 06 11:03:53.000 [notice] Bootstrapped 100%: Done
+Apr 06 11:03:55.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:53:46.000 [notice] Interrupt: exiting cleanly.
+Apr 06 11:53:54.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening log file.
+Apr 06 11:53:54.392 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:53:54.392 [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 06 11:53:54.392 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:53:54.392 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:53:54.396 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:53:54.396 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:53:54.000 [warn] Your log may contain sensitive information - you're logging more than "notice". Don't log unless it serves an important reason. Overwrite the log afterwards.
+Apr 06 11:53:54.000 [debug] tor_disable_debugger_attach(): Attemping to disable debugger attachment to Tor for unprivileged users.
+Apr 06 11:53:54.000 [debug] tor_disable_debugger_attach(): Debugger attachment disabled for unprivileged users.
+Apr 06 11:53:54.000 [info] tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"
+Apr 06 11:53:54.000 [debug] parse_dir_authority_line(): Trusted 100 dirserver at 128.31.0.39:9131 (9695)
diff --git a/test/util/data/tor_log b/test/util/data/tor_log
new file mode 100644
index 0000000..0a4464e
--- /dev/null
+++ b/test/util/data/tor_log
@@ -0,0 +1,21 @@
+Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
+Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
+Apr 06 11:03:39.832 [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 06 11:03:39.833 [notice] This version is not a stable Tor release. Expect more bugs than usual.
+Apr 06 11:03:39.833 [notice] Read configuration file "/home/atagar/.tor/torrc".
+Apr 06 11:03:39.838 [notice] Opening Socks listener on 127.0.0.1:9050
+Apr 06 11:03:39.838 [notice] Opening Control listener on 127.0.0.1:9051
+Apr 06 11:03:39.000 [notice] Bootstrapped 0%: Starting
+Apr 06 11:03:42.000 [notice] Bootstrapped 45%: Asking for relay descriptors
+Apr 06 11:03:43.000 [notice] Bootstrapped 50%: Loading relay descriptors
+Apr 06 11:03:49.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:03:51.000 [notice] Bootstrapped 55%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 63%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 69%: Loading relay descriptors
+Apr 06 11:03:51.000 [notice] Bootstrapped 74%: Loading relay descriptors
+Apr 06 11:03:52.000 [notice] Bootstrapped 80%: Connecting to the Tor network
+Apr 06 11:03:52.000 [notice] Bootstrapped 90%: Establishing a Tor circuit
+Apr 06 11:03:53.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
+Apr 06 11:03:53.000 [notice] Bootstrapped 100%: Done
+Apr 06 11:03:55.000 [notice] New control connection opened from 127.0.0.1.
+Apr 06 11:53:46.000 [notice] Interrupt: exiting cleanly.
diff --git a/test/util/read_tor_log.py b/test/util/read_tor_log.py
new file mode 100644
index 0000000..3b2ca01
--- /dev/null
+++ b/test/util/read_tor_log.py
@@ -0,0 +1,59 @@
+import os
+import unittest
+
+from nyx.util.log import LogEntry, read_tor_log
+
+
+def data_path(filename):
+ return os.path.join(os.path.dirname(__file__), 'data', filename)
+
+
+class TestReadTorLog(unittest.TestCase):
+ def test_general_log(self):
+ entries = list(read_tor_log(data_path('tor_log')))
+ self.assertEqual(21, len(entries))
+
+ self.assertEqual(LogEntry(1333738426, 'NOTICE', 'Interrupt: exiting cleanly.'), entries[0])
+ self.assertEqual(LogEntry(1333735419, 'NOTICE', 'Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.'), entries[-1])
+
+ def test_with_multiple_tor_instances(self):
+ entries = list(read_tor_log(data_path('multiple_tor_instances')))
+ self.assertEqual(12, len(entries))
+
+ self.assertEqual(LogEntry(1333738434, 'DEBUG', 'parse_dir_authority_line(): Trusted 100 dirserver at 128.31.0.39:9131 (9695)'), entries[0])
+ self.assertEqual(LogEntry(1333738434, 'INFO', 'tor_lockfile_lock(): Locking "/home/atagar/.tor/lock"'), entries[1])
+ self.assertEqual(LogEntry(1333738434, 'NOTICE', 'Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening log file.'), entries[-1])
+
+ def test_with_read_limit(self):
+ entries = list(read_tor_log(data_path('tor_log'), 5))
+ self.assertEqual(5, len(entries))
+ self.assertEqual('Interrupt: exiting cleanly.', entries[0].message)
+ self.assertEqual('Bootstrapped 90%: Establishing a Tor circuit', entries[-1].message)
+
+ def test_with_empty_file(self):
+ entries = list(read_tor_log(data_path('empty_file')))
+ self.assertEqual(0, len(entries))
+
+ def test_with_missing_path(self):
+ self.assertRaises(IOError, list, read_tor_log(data_path('no_such_path')))
+
+ def test_with_malformed_line(self):
+ try:
+ list(read_tor_log(data_path('malformed_line')))
+ self.fail("Malformed content should've raised a ValueError")
+ except ValueError as exc:
+ self.assertTrue("has a line that doesn't match the format we expect: Apr 06 11:03:53.000" in str(exc))
+
+ def test_with_malformed_runlevel(self):
+ try:
+ list(read_tor_log(data_path('malformed_runlevel')))
+ self.fail("Malformed content should've raised a ValueError")
+ except ValueError as exc:
+ self.assertTrue("has an unrecognized runlevel: [unrecognized]" in str(exc))
+
+ def test_with_malformed_date(self):
+ try:
+ list(read_tor_log(data_path('malformed_date')))
+ self.fail("Malformed content should've raised a ValueError")
+ except ValueError as exc:
+ self.assertTrue("has a timestamp we don't recognize: Zed 06 11:03:52.000" in str(exc))
_______________________________________________
tor-commits mailing list
tor-commits@xxxxxxxxxxxxxxxxxxxx
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-commits