April 2014 - tor-commits - lists.torproject.org

[bridgedb/develop] Move log configuration functions to bridgedb.util module.
by isis＠torproject.org 08 Apr '14

08 Apr '14

commit cc83936455cbe4e39016b3aef9d345652a82130d Author: Isis Lovecruft <isis(a)torproject.org> Date: Mon Apr 7 12:17:49 2014 +0000 Move log configuration functions to bridgedb.util module. * MOVE `Main.configureLogging()` → `util.configureLogging()`. * CHANGE `configureLogging()` function to use `logging.config.dictConfig()` with automatic safelogging filters from `bridgedb.safelog` module. * ADD `util._getRotatingFileHandlers()` function for chmod/chown'ing the rotated log files to be readable only by the running process owner. * ADD `util.JustifiedLogFormatter` class for justified printing of log messages when the config options LOG_TRACE and LOG_THREADS are enabled (this extra information is then printed in justified columns on the left, leaving the actual log messages left-justified to the same width on the right, which in my opinion is much easier to read quickly). --- lib/bridgedb/Main.py | 39 +--------- lib/bridgedb/util.py | 192 ++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 193 insertions(+), 38 deletions(-) diff --git a/lib/bridgedb/Main.py b/lib/bridgedb/Main.py index e29e991..90a03ef 100644 --- a/lib/bridgedb/Main.py +++ b/lib/bridgedb/Main.py @@ -13,7 +13,6 @@ import signal import sys import time import logging -import logging.handlers import gettext from twisted.internet import reactor @@ -29,42 +28,6 @@ import bridgedb.Dist as Dist import bridgedb.Time as Time import bridgedb.Storage -def configureLogging(cfg): - """Set up Python's logging subsystem based on the configuratino. - """ - - # Turn on safe logging by default - safelogging = getattr(cfg, 'SAFELOGGING', True) - - level = getattr(cfg, 'LOGLEVEL', 'WARNING') - level = getattr(logging, level) - logfile = getattr(cfg, 'LOGFILE', "") - logfile_count = getattr(cfg, 'LOGFILE_COUNT', 5) - logfile_rotate_size = getattr(cfg, 'LOGFILE_ROTATE_SIZE', 10000000) - safelog.setSafeLogging(safelogging) - - logging.getLogger().setLevel(level) - if logfile: - handler = logging.handlers.RotatingFileHandler(logfile, 'a', - logfile_rotate_size, - logfile_count) - formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s', - "%b %d %H:%M:%S") - handler.setFormatter(formatter) - logging.getLogger().addHandler(handler) - - logging.info("Logger Started.") - logging.info("Level: %s", level) - if logfile: - logging.info("Log File: %s", os.path.abspath(logfile)) - logging.info("Log File Count: %d", logfile_count) - logging.info("Rotate Logs After Size: %d", logfile_rotate_size) - else: - logging.info("Logging to stderr") - if safelogging: - logging.info("Safe Logging: Enabled") - else: - logging.warn("Safe Logging: Disabled") def load(state, splitter, clear=False): """Read and parse all descriptors, and load into a bridge splitter. @@ -461,7 +424,7 @@ def startup(options): # called. Otherwise a default handler that logs to the console will be # created by the imported module, and all further calls to # :func:`logging.basicConfig` will be ignored. - configureLogging(config) + util.configureLogging(config) if options['dump-bridges'] or (options.subCommand is not None): runSubcommand(options, config) diff --git a/lib/bridgedb/util.py b/lib/bridgedb/util.py index ebca7e1..691b9bc 100644 --- a/lib/bridgedb/util.py +++ b/lib/bridgedb/util.py @@ -11,5 +11,197 @@ """Common utilities for BridgeDB.""" +import logging +import logging.config +import logging.handlers +import os +def _getLogHandlers(logToFile=True, logToStderr=True): + """Get the appropriate list of log handlers. + + :param bool logToFile: If ``True``, add a logfile handler. + :param bool logToStderr: If ``True``, add a stream handler to stderr. + :rtype: list + :returns: A list containing the appropriate log handler names from the + :class:`logging.config.dictConfigClass`. + """ + logHandlers = [] + if logToFile: + logHandlers.append('rotating') + if logToStderr: + logHandlers.append('console') + return logHandlers + +def _getRotatingFileHandler(filename, mode='a', filesize=1000000, filecount=0, + encoding='utf-8', uid=None, gid=None): + """Get a :class:`logging.RotatingFileHandler` with a logfile which is + readable+writable only by the given **uid** and **gid**. + + :param str filename: The full path to the log file. + :param str mode: The mode to open **filename** with. (default: ``'a'``) + :param int filesize: Rotate logfiles after they have grown to this size in + bytes. + :param int filecount: The number of logfiles to keep in rotation. + :param str encoding: The encoding for the logfile. + :param int uid: The owner UID to set on the logfile. + :param int gid: The GID to set on the logfile. + :rtype: :class:`logging.handlers.RotatingFileHandler` + :returns: A logfile handler which will rotate files and chown/chmod newly + created files. + """ + # Default to the current process owner's uid and gid: + uid = os.getuid() if not uid else uid + gid = os.getgid() if not gid else gid + + if not os.path.exists(filename): + open(filename, 'a').close() + os.chown(filename, uid, gid) + os.chmod(filename, os.ST_WRITE | os.ST_APPEND) + + fileHandler = logging.handlers.RotatingFileHandler(filename, mode, + maxBytes=filesize, + backupCount=filecount, + encoding=encoding) + return fileHandler + +def configureLogging(cfg): + """Set up Python's logging subsystem based on the configuration. + + :type cfg: :class:`~bridgedb.persistent.Conf` + :param cfg: The current configuration, including any in-memory settings. + """ + from bridgedb import safelog + + # Turn on safe logging by default: + safelogging = getattr(cfg, 'SAFELOGGING', True) + safelog.setSafeLogging(safelogging) + + level = getattr(cfg, 'LOGLEVEL', 'WARNING') + logLevel = getattr(logging, level, 0) + logStderr = getattr(cfg, 'LOG_TO_STDERR', False) + logfileName = getattr(cfg, 'LOGFILE', "") + logfileCount = getattr(cfg, 'LOGFILE_COUNT', 3) - 1 + logfileRotateSize = getattr(cfg, 'LOGFILE_ROTATE_SIZE', 10000000) + logThreads = getattr(cfg, 'LOG_THREADS', False) + logTrace = getattr(cfg, 'LOG_TRACE', False) + logTimeFormat = getattr(cfg, 'LOG_TIME_FORMAT', "%H:%M:%S") + + logFilters = [] + if safelogging: + logFilters = ['safelogEmail', 'safelogIPv4', 'safelogIPv6'] + + logConfig = { + 'version': 1, + 'filters': { + 'safelogEmail': {'()': safelog.SafelogEmailFilter}, + 'safelogIPv4': {'()': safelog.SafelogIPv4Filter}, + 'safelogIPv6': {'()': safelog.SafelogIPv6Filter}, + }, + 'formatters': { + 'default': {'()': JustifiedLogFormatter, + # These values below are kwargs passed to + # :class:`JustifiedFormatter`: + 'logThreads': logThreads, + 'logTrace': logTrace, + 'datefmt': logTimeFormat}, + }, + 'handlers': { + 'console': {'class': 'logging.StreamHandler', + 'level': logLevel, + 'formatter': 'default', + 'filters': logFilters}, + 'rotating': {'()': _getRotatingFileHandler, + 'level': logLevel, + 'formatter': 'default', + 'filters': logFilters, + # The values below are passed to the handler creator, + # :func:`getChownedFileHandler`, as kwargs: + 'filename': logfileName, + 'filesize': logfileRotateSize, + 'filecount': logfileCount}, + }, + 'root': { + 'handlers': _getLogHandlers(logfileName, logStderr), + 'level': logLevel, + }, + } + + logging.config.dictConfig(logConfig) + + logging.info("Logger Started.") + logging.info("Level: %s", logLevel) + logging.info("Safe Logging: %sabled" % ("En" if safelogging else "Dis")) + + +class JustifiedLogFormatter(logging.Formatter): + """A logging formatter which pretty prints thread and calling function + information, in addition to the normal timestamp, log level, and log + message. + + :ivar int width: The width of the column for the calling function + information, if the latter is to be included. + """ + width = 30 + + def __init__(self, logThreads=False, logTrace=False, + datefmt="%H:%M:%s"): + """If **logTrace** is ``True``, the line number, module name, and + function name where the logger was called will be included in the + message, and the width of this information will always equal ``width``. + + :param bool logThreads: If ``True``, include the current thread name + and ID in formatted log messages. + :param bool logTrace: If ``True``, include information on the calling + function in formatted log messages. + """ + super(JustifiedLogFormatter, self).__init__(datefmt=datefmt) + self.logThreads = logThreads + self.logTrace = logTrace + + _fmt = ["%(asctime)s %(levelname)-7.7s"] + if self.logThreads: + _fmt.append("[%(threadName)s id:%(thread)d]") + _fmt.append("%(callingFunc)s") + _fmt.append("%(message)s") + + self._fmt = " ".join(_fmt) + + def _formatCallingFuncName(self, record): + """Format the combined module name and function name of the place where + the log message/record was recorded, so that the formatted string is + left-justified and not longer than the :cvar:`width`. + + :type record: :class:`logging.LogRecord` + :param record: A record of an event created by calling a logger. + :returns: The :class:`logging.LogRecord` with its ``message`` + attribute rewritten to contain the module and function name, + truncated to ``width``, or padded on the right with spaces as is + necessary. + """ + callingFunc = "" + if self.logTrace: + # The '.' character between the module name and function name + # would otherwise be interpreted as a format string specifier, so + # we must specify ``chr(46)``: + lineno = "L%s:" % record.lineno + caller = "%s%-s%s" % (lineno.rjust(6), record.module, chr(46)) + maxFuncNameWidth = self.width - 2 - len(caller) + funcName = record.funcName + if len(funcName) > maxFuncNameWidth: + funcName = record.funcName[:maxFuncNameWidth] + caller += "%s()" % (funcName) + callingFunc = caller.ljust(self.width) + + record.callingFunc = callingFunc + return record + + def format(self, record): + """Reformat this log **record** to neatly print thread and function + traces, if configured to do so. + + :type record: :class:`logging.LogRecord` + :param record: A record of an event created by calling a logger. + """ + record = self._formatCallingFuncName(record) + return super(JustifiedLogFormatter, self).format(record)

1 0

[bridgedb/develop] Fix recursion in filtered log call in validation used by log filter.
by isis＠torproject.org 08 Apr '14

08 Apr '14

commit d68f8e2427a5b9623a7d4907c177bf2cc46da9b2 Author: Isis Lovecruft <isis(a)torproject.org> Date: Mon Apr 7 12:32:47 2014 +0000 Fix recursion in filtered log call in validation used by log filter. We can't log an IP address in a IP validation function which is used by a log filter in `bridgedb.safelog`, because the log call made in the validation function `bridgedb.parse.addr._isIPv()` will call the filter, which will call the validation function, which will call the logger, which will call the filter… --- lib/bridgedb/parse/addr.py | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/lib/bridgedb/parse/addr.py b/lib/bridgedb/parse/addr.py index 927de2f..455b953 100644 --- a/lib/bridgedb/parse/addr.py +++ b/lib/bridgedb/parse/addr.py @@ -181,20 +181,26 @@ def isIPAddress(ip, compressed=True): def _isIPv(version, ip): """Check if **ip** is a certain **version** (IPv4 or IPv6). + .. warning: Do *not* put any calls to the logging module in this function, + or else an infinite recursion will occur when the call is made, due + the the log :class:`~logging.Filter`s in :mod:`~bridgedb.safelog` + using this function to validate matches from the regular expression + for IP addresses. + :param integer version: The IPv[4|6] version to check; must be either - ``4`` or ``6``. + ``4`` or ``6``. Any other value will be silently changed to ``4``. :param ip: The IP address to check. May be an any type which :class:`ipaddr.IPAddress` will accept. :rtype: boolean :returns: ``True``, if the address is an IPv4 address. """ try: - ip = ipaddr.IPAddress(ip, version=version) - except ipaddr.AddressValueError: - logging.debug("Address %s seems not to be IPv%d." % (ip, version)) + ipaddr.IPAddress(ip, version=version) + except (ipaddr.AddressValueError, Exception): return False else: return True + return False def isIPv4(ip): """Check if an address is IPv4.

1 0

[bridgedb/develop] Merge branch 'fix/9199-safelogging' into develop
by isis＠torproject.org 08 Apr '14

08 Apr '14

commit 0275fa56cbd39c6f452cc973ac34d955f0ec6603 Merge: 33499da d68f8e2 Author: Isis Lovecruft <isis(a)torproject.org> Date: Tue Apr 8 16:08:19 2014 +0000 Merge branch 'fix/9199-safelogging' into develop bridgedb.conf | 18 +- doc/sphinx/source/bridgedb.rst | 1 + doc/sphinx/source/bridgedb.safelog.rst | 9 + doc/sphinx/source/conf.py | 1 + lib/bridgedb/Bridges.py | 10 +- lib/bridgedb/Dist.py | 23 ++- lib/bridgedb/EmailServer.py | 24 +-- lib/bridgedb/HTTPServer.py | 15 +- lib/bridgedb/Main.py | 54 +---- lib/bridgedb/parse/addr.py | 14 +- lib/bridgedb/safelog.py | 197 +++++++++++++++++++ lib/bridgedb/test/test_safelog.py | 336 ++++++++++++++++++++++++++++++++ lib/bridgedb/util.py | 201 ++++++++++++++++++- 13 files changed, 806 insertions(+), 97 deletions(-)

1 0

[bridgedb/develop] Add unittests for bridgedb.safelog module.
by isis＠torproject.org 08 Apr '14

08 Apr '14

commit 0dc4e5b040e7dbe9714ea5b563caa32182a07cc7 Author: Isis Lovecruft <isis(a)torproject.org> Date: Mon Apr 7 12:28:07 2014 +0000 Add unittests for bridgedb.safelog module. * FIXES #9875 Write tests for BridgeDB's logger --- lib/bridgedb/test/test_safelog.py | 336 +++++++++++++++++++++++++++++++++++++ 1 file changed, 336 insertions(+) diff --git a/lib/bridgedb/test/test_safelog.py b/lib/bridgedb/test/test_safelog.py new file mode 100644 index 0000000..bc92305 --- /dev/null +++ b/lib/bridgedb/test/test_safelog.py @@ -0,0 +1,336 @@ +# -*- coding: utf-8 -*- + +"""Unittests for :mod:`bridgedb.safelog`.""" + +import re + +from twisted.internet import defer +from twisted.test.proto_helpers import StringTransport +from twisted.trial import unittest + +from bridgedb import safelog + + +class SafelogTests(unittest.TestCase): + """Tests for functions and attributes in :mod:`bridgedb.safelog`.""" + + def setUp(self): + """Create a logger at debug level and add the filter to be tested.""" + self.logfile = StringTransport() + self.handler = safelog.logging.StreamHandler(self.logfile) + self.logger = safelog.logging.getLogger(self.__class__.__name__) + self.logger.setLevel(10) + self.logger.addHandler(self.handler) + self.sensitiveData = 'Nicholas Bourbaki' + + def tearDown(self): + """Rewind and truncate the logfile so that we have an empty one.""" + self.logfile.clear() + + def test_setSafeLogging_off(self): + """Calls to ``logSafely()`` should return the original data when + ``safe_logging`` is disabled. + """ + safelog.setSafeLogging(False) + self.logger.warn("Got a connection from %s..." + % safelog.logSafely(self.sensitiveData)) + contents = self.logfile.value() + self.assertIsNotNone(contents) + #self.assertSubstring("Got a connection from", contents) + #self.assertSubstring(self.sensitiveData, contents) + #self.failIfSubstring("[scrubbed]", contents) + + def test_setSafeLogging_on(self): + """Calls to ``logSafely()`` should return ``"[scrubbed]"`` for any + arbitrary data when ``safe_logging`` is enabled. + """ + safelog.setSafeLogging(True) + self.logger.warn("Got a connection from %s..." + % safelog.logSafely(self.sensitiveData)) + contents = self.logfile.value() + self.assertIsNotNone(contents) + #self.assertSubstring("Got a connection from", contents) + #self.failIfSubstring(self.sensitiveData, contents) + #self.assertSubstring("[scrubbed]", contents) + + +class BaseSafelogFilterTests(unittest.TestCase): + """Unittests for :class:`bridgedb.safelog.BaseSafelogFilter`.""" + + def setUp(self): + safelog.setSafeLogging(True) + self.logfile = StringTransport() + self.handler = safelog.logging.StreamHandler(self.logfile) + self.logger = safelog.logging.getLogger(self.__class__.__name__) + self.logger.setLevel(10) + self.logger.addHandler(self.handler) + self.filter = safelog.BaseSafelogFilter() + self.logger.addFilter(self.filter) + + self.logMessage = "testing 1 2 3" + self.record = safelog.logging.LogRecord('name', 10, __file__, 1337, + self.logMessage, {}, None) + + def test_doubleCheck(self): + """BaseSafelogFilter.doubleCheck() should always return True.""" + checked = self.filter.doubleCheck(self.logMessage) + self.assertTrue(checked) + + def test_filter(self): + """Test filtering a log record with no ``easyFind`` nor ``pattern``. + + The ``LogRecord.message`` shouldn't change. + """ + filtered = self.filter.filter(self.record) + self.assertEqual(filtered.getMessage(), self.logMessage) + + def test_filter_withEasyFind(self): + """Test filtering a log record with ``easyFind``, but no ``pattern``. + + The ``LogRecord.message`` shouldn't change. + """ + self.filter.easyFind = "2" + filtered = self.filter.filter(self.record) + self.assertEqual(filtered.getMessage(), self.logMessage) + + def test_filter_withPattern(self): + """Test filtering a log record with ``easyFind`` and ``pattern``.""" + self.filter.easyFind = "2" + self.filter.pattern = re.compile("1 2 3") + filtered = self.filter.filter(self.record) + self.assertEqual(filtered.msg, "testing [scrubbed]") + + +class SafelogEmailFilterTests(unittest.TestCase): + """Unittests for :class:`bridgedb.safelog.SafelogEmailFilter`.""" + + def setUp(self): + """Create a logger at debug level and add the filter to be tested.""" + self.logfile = StringTransport() + self.handler = safelog.logging.StreamHandler(self.logfile) + self.filter = safelog.SafelogEmailFilter() + self.logger = safelog.logging.getLogger(self.__class__.__name__) + self.logger.setLevel(10) + self.logger.addHandler(self.handler) + self.logger.addFilter(self.filter) + self.s1 = "Here is an email address: " + self.s2 = "blackhole(a)torproject.org" + + def test_filter_withPattern(self): + """Test filtering a log record with ``easyFind`` and ``pattern``.""" + record = safelog.logging.LogRecord('name', 10, __file__, 1337, + "testing blackhole(a)torproject.org", + {}, None) + filtered = self.filter.filter(record) + self.assertEqual(filtered.msg, "testing [scrubbed]") + + def test_debugLevel(self): + self.logger.debug("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + # XXX We should test the following assertions for each test_*Level + # method, however, twisted.trial doesn't give us an easy way to wait + # for the logging module to complete it's IO operations. + #self.assertSubstring(self.s1, contents) + #self.failIfSubstring(self.s2, contents) + + def test_infoLevel(self): + self.logger.info("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_warnLevel(self): + self.logger.warn("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_errorLevel(self): + self.logger.error("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_exceptionLevel(self): + try: + raise Exception("%s %s" % (self.s1, self.s2)) + except Exception as error: + self.logger.exception(error) + + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + #self.assertSubstring(self.s1, contents) + # If an email address is within an Exception message, it doesn't get + # sanitised. + #self.assertSubstring(self.s2, contents) + + def test_withSafeLoggingDisabled(self): + """The filter should be disabled if ``safe_logging`` is disabled.""" + safelog.setSafeLogging(False) + self.logger.info("%s %s" % (self.s1, self.s2)) + self.logfile.io.flush() + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + #self.assertSubstring(self.s1, contents) + #self.assertSubstring(self.s2, contents) + + +class SafelogIPv4FilterTests(unittest.TestCase): + """Unittests for :class:`bridgedb.safelog.SafelogIPv4Filter`.""" + + def setUp(self): + """Create a logger at debug level and add the filter to be tested.""" + self.logfile = StringTransport() + self.handler = safelog.logging.StreamHandler(self.logfile) + self.filter = safelog.SafelogIPv4Filter() + self.logger = safelog.logging.getLogger(str(self.__class__.__name__)) + self.logger.addHandler(self.handler) + self.logger.addFilter(self.filter) + self.logger.setLevel(10) + self.s1 = "There's an IPv4 address at the end of this book: " + self.s2 = "1.2.3.4" + + def test_filter_withPattern(self): + """Test filtering a log record with ``easyFind`` and ``pattern``.""" + record = safelog.logging.LogRecord('name', 10, __file__, 1337, + "testing 1.2.3.4", + {}, None) + filtered = self.filter.filter(record) + self.assertIsInstance(filtered, safelog.logging.LogRecord) + + def test_doubleCheck_IPv4(self): + checked = self.filter.doubleCheck("1.2.3.4") + self.assertIs(checked, True) + + def test_doubleCheck_IPv6(self): + checked = self.filter.doubleCheck("2af1:a470:9b36::a1:3:82") + self.assertIsNot(checked, True) + + def test_debugLevel(self): + self.logger.debug("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_infoLevel(self): + self.logger.info("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_warnLevel(self): + self.logger.warn("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_errorLevel(self): + self.logger.error("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_exceptionLevel(self): + try: + raise Exception("%s %s" % (self.s1, self.s2)) + except Exception as error: + self.logger.exception(error) + + self.logfile.io.flush() + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_withSafeLoggingDisabled(self): + """The filter should be disabled if ``safe_logging`` is disabled.""" + safelog.setSafeLogging(False) + self.logger.info("%s %s" % (self.s1, self.s2)) + self.logfile.io.flush() + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + +class SafelogIPv6FilterTests(unittest.TestCase): + """Unittests for :class:`bridgedb.safelog.SafelogIPv6Filter`.""" + + def setUp(self): + """Create a logger at debug level and add the filter to be tested.""" + self.logfile = StringTransport() + self.handler = safelog.logging.StreamHandler(self.logfile) + self.filter = safelog.SafelogIPv6Filter() + self.logger = safelog.logging.getLogger(str(self.__class__.__name__)) + self.logger.addHandler(self.handler) + self.logger.addFilter(self.filter) + self.logger.setLevel(10) + self.s1 = "There's an IPv6 address at the end of this book: " + self.s2 = "2af1:a470:9b36::a1:3:82" + + def test_filter_withPattern(self): + """Test filtering a log record with ``easyFind`` and ``pattern``.""" + record = safelog.logging.LogRecord('name', 10, __file__, 1337, + "2af1:a470:9b36::a1:3:82", + {}, None) + filtered = self.filter.filter(record) + self.assertIsInstance(filtered, safelog.logging.LogRecord) + + def test_doubleCheck_IPv4(self): + checked = self.filter.doubleCheck("1.2.3.4") + self.assertIsNot(checked, True) + + def test_doubleCheck_IPv6(self): + checked = self.filter.doubleCheck("2af1:a470:9b36::a1:3:82") + self.assertIs(checked, True) + + def test_debugLevel(self): + self.logger.debug("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_infoLevel(self): + self.logger.info("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_warnLevel(self): + self.logger.warn("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_errorLevel(self): + self.logger.error("%s %s" % (self.s1, self.s2)) + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + + def test_exceptionLevel(self): + try: + raise Exception("%s %s" % (self.s1, self.s2)) + except Exception as error: + self.logger.exception(error) + + self.logfile.io.flush() + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents) + #self.assertSubstring(self.s1, contents) + # If an IP address is within an Exception message, it doesn't get + # sanitised. + #self.assertSubstring(self.s2, contents) + + def test_withSafeLoggingDisabled(self): + """The filter should be disabled if ``safe_logging`` is disabled.""" + safelog.setSafeLogging(False) + self.logger.info("%s %s" % (self.s1, self.s2)) + + self.logfile.io.flush() + self.logfile.io.seek(0) + contents = self.logfile.value() + self.assertIsNotNone(contents)

1 0

[tor/master] Fix to 9841 fix: setting a token to NULL should clear it
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit 09dbcf3b82c6db76024a5345b98f34028b40c30c Author: Nick Mathewson <nickm(a)torproject.org> Date: Fri Apr 4 12:01:49 2014 -0400 Fix to 9841 fix: setting a token to NULL should clear it Found by testing with chutney. The old behavior was "fail an assertion", which obviously isn't optimal. Bugfix on 8b9a2cb68b290e550695124d7ef0511225b451d5; bug not in any released version. --- src/or/circuitlist.c | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index 8ab673c..be71fdd 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -1233,6 +1233,11 @@ circuit_set_rend_token(or_circuit_t *circ, int is_rend_circ, if (circ->rendinfo) circuit_clear_rend_token(circ); + if (token == NULL) { + /* We were only trying to remove this token, not set a new one. */ + return; + } + found_circ = digestmap_get(map, (const char *)token); if (found_circ) { tor_assert(found_circ != circ);

1 0

[tor/master] Tests for rend_token maps
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit fb595922b12c9ab89f51527def68e9b71386caf7 Author: Nick Mathewson <nickm(a)torproject.org> Date: Thu Feb 13 15:24:15 2014 -0500 Tests for rend_token maps This gets coverage of everything except for the cases which should be impossible. --- src/test/test_circuitlist.c | 85 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 85 insertions(+) diff --git a/src/test/test_circuitlist.c b/src/test/test_circuitlist.c index 720b407..ee62cd2 100644 --- a/src/test/test_circuitlist.c +++ b/src/test/test_circuitlist.c @@ -161,8 +161,93 @@ test_clist_maps(void *arg) UNMOCK(circuitmux_detach_circuit); } +static void +test_rend_token_maps(void *arg) +{ + or_circuit_t *c1, *c2, *c3, *c4; + const uint8_t tok1[REND_TOKEN_LEN] = "The cat can't tell y"; + const uint8_t tok2[REND_TOKEN_LEN] = "ou its name, and it "; + const uint8_t tok3[REND_TOKEN_LEN] = "doesn't really care."; + /* -- Adapted from a quote by Fredrik Lundh. */ + + (void)arg; + (void)tok1; //xxxx + c1 = or_circuit_new(0, NULL); + c2 = or_circuit_new(0, NULL); + c3 = or_circuit_new(0, NULL); + c4 = or_circuit_new(0, NULL); + + tt_int_op(strlen((char*)tok1), ==, REND_TOKEN_LEN); + + /* No maps; nothing there. */ + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok1)); + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok1)); + + circuit_set_rendezvous_cookie(c1, tok1); + circuit_set_intro_point_digest(c2, tok2); + + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok3)); + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok3)); + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok2)); + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok1)); + + /* Without purpose set, we don't get the circuits */ + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok1)); + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok2)); + + c1->base_.purpose = CIRCUIT_PURPOSE_REND_POINT_WAITING; + c2->base_.purpose = CIRCUIT_PURPOSE_INTRO_POINT; + + /* Okay, make sure they show up now. */ + tt_ptr_op(c1, ==, circuit_get_rendezvous(tok1)); + tt_ptr_op(c2, ==, circuit_get_intro_point(tok2)); + + /* Two items at the same place with the same token. */ + c3->base_.purpose = CIRCUIT_PURPOSE_REND_POINT_WAITING; + circuit_set_rendezvous_cookie(c3, tok2); + tt_ptr_op(c2, ==, circuit_get_intro_point(tok2)); + tt_ptr_op(c3, ==, circuit_get_rendezvous(tok2)); + + /* Marking a circuit makes it not get returned any more */ + circuit_mark_for_close(TO_CIRCUIT(c1), END_CIRC_REASON_FINISHED); + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok1)); + circuit_free(TO_CIRCUIT(c1)); + c1 = NULL; + + /* Freeing a circuit makes it not get returned any more. */ + circuit_free(TO_CIRCUIT(c2)); + c2 = NULL; + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok2)); + + /* c3 -- are you still there? */ + tt_ptr_op(c3, ==, circuit_get_rendezvous(tok2)); + /* Change its cookie. This never happens in Tor per se, but hey. */ + c3->base_.purpose = CIRCUIT_PURPOSE_INTRO_POINT; + circuit_set_intro_point_digest(c3, tok3); + + tt_ptr_op(NULL, ==, circuit_get_rendezvous(tok2)); + tt_ptr_op(c3, ==, circuit_get_intro_point(tok3)); + + /* Now replace c3 with c4. */ + c4->base_.purpose = CIRCUIT_PURPOSE_INTRO_POINT; + circuit_set_intro_point_digest(c4, tok3); + + tt_ptr_op(c4, ==, circuit_get_intro_point(tok3)); + + tt_ptr_op(c3->rendinfo, ==, NULL); + tt_ptr_op(c4->rendinfo, !=, NULL); + test_mem_op(c4->rendinfo, ==, tok3, REND_TOKEN_LEN); + + done: + circuit_free(TO_CIRCUIT(c1)); + circuit_free(TO_CIRCUIT(c2)); + circuit_free(TO_CIRCUIT(c3)); + circuit_free(TO_CIRCUIT(c4)); +} + struct testcase_t circuitlist_tests[] = { { "maps", test_clist_maps, TT_FORK, NULL, NULL }, + { "rend_token_maps", test_rend_token_maps, TT_FORK, NULL, NULL }, END_OF_TESTCASES };

1 0

[tor/master] Protocol_Warn when a rendezvous cookie is used twice.
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit 8f16a77d6ae6bfc8f7983decf8269ae70ca1cc5e Author: Nick Mathewson <nickm(a)torproject.org> Date: Fri Apr 4 12:17:16 2014 -0400 Protocol_Warn when a rendezvous cookie is used twice. --- src/or/circuitlist.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index a5b43f7..065f980 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -1343,8 +1343,14 @@ circuit_set_rend_token(or_circuit_t *circ, int is_rend_circ, if (found_circ) { tor_assert(found_circ != circ); circuit_clear_rend_token(found_circ); - if (! found_circ->base_.marked_for_close) + if (! found_circ->base_.marked_for_close) { circuit_mark_for_close(TO_CIRCUIT(found_circ), END_CIRC_REASON_FINISHED); + if (is_rend_circ) { + log_fn(LOG_PROTOCOL_WARN, LD_REND, + "Duplicate rendezvous cookie (%s...) used on two circuits", + hex_str((const char*)token, 4)); /* only log first 4 chars */ + } + } } /* Now set up the rendinfo */

1 0

[tor/master] Merge remote-tracking branch 'public/bug9841_024_v2' into bug9841_025
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit 1bb6e3b503bfe4f7f5a8ee707433b6f9973e4dea Merge: fb59592 09dbcf3 Author: Nick Mathewson <nickm(a)torproject.org> Date: Fri Apr 4 12:05:51 2014 -0400 Merge remote-tracking branch 'public/bug9841_024_v2' into bug9841_025 src/or/circuitlist.c | 5 +++++ 1 file changed, 5 insertions(+)

1 0

[tor/master] Test for circuit_set_rend_token(., ., NULL)
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit d22ce149c82c257398555d35cf76cab4973a8cf9 Author: Nick Mathewson <nickm(a)torproject.org> Date: Fri Apr 4 12:06:54 2014 -0400 Test for circuit_set_rend_token(.,.,NULL) --- src/test/test_circuitlist.c | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/test/test_circuitlist.c b/src/test/test_circuitlist.c index ee62cd2..2cfe556 100644 --- a/src/test/test_circuitlist.c +++ b/src/test/test_circuitlist.c @@ -238,6 +238,11 @@ test_rend_token_maps(void *arg) tt_ptr_op(c4->rendinfo, !=, NULL); test_mem_op(c4->rendinfo, ==, tok3, REND_TOKEN_LEN); + /* Now clear c4's cookie. */ + circuit_set_intro_point_digest(c4, NULL); + tt_ptr_op(c4->rendinfo, ==, NULL); + tt_ptr_op(NULL, ==, circuit_get_intro_point(tok3)); + done: circuit_free(TO_CIRCUIT(c1)); circuit_free(TO_CIRCUIT(c2));

1 0

[tor/master] Merge remote-tracking branch 'public/bug9841_025'
by nickm＠torproject.org 08 Apr '14

08 Apr '14

commit fffc59b0e941f12e1588e0604c8295ecc0679150 Merge: f0bce2d 8f16a77 Author: Nick Mathewson <nickm(a)torproject.org> Date: Tue Apr 8 12:06:03 2014 -0400 Merge remote-tracking branch 'public/bug9841_025' changes/bug9841 | 7 ++ src/or/circuitlist.c | 164 ++++++++++++++++++++++++++++++++++++++----- src/or/circuitlist.h | 6 +- src/or/or.h | 33 +++++---- src/or/rendmid.c | 14 ++-- src/test/test_circuitlist.c | 90 ++++++++++++++++++++++++ 6 files changed, 275 insertions(+), 39 deletions(-)

1 0