commit b5734531a5d1e8789638a7c1d8cb45e8650fd3af Author: Isis Lovecruft isis@torproject.org Date: Mon Apr 7 11:23:47 2014 +0000

Move manual safelog setting and functions to bridgedb.safelog module.

* MOVE util.safe_logging → safelog.safe_logging. * MOVE util.set_safe_logging → safelog.setSafeLogging * MOVE util.logSafely → safelog.logSafely * REMOVE manual calls to `logSafely()` for values which are automatically scrubbed. --- lib/bridgedb/Bridges.py | 10 +++++----- lib/bridgedb/Dist.py | 23 +++++++++++------------ lib/bridgedb/EmailServer.py | 24 ++++++++++++------------ lib/bridgedb/HTTPServer.py | 15 +++++++-------- lib/bridgedb/Main.py | 17 +++++++++-------- lib/bridgedb/safelog.py | 1 + lib/bridgedb/util.py | 9 --------- 7 files changed, 45 insertions(+), 54 deletions(-)

diff --git a/lib/bridgedb/Bridges.py b/lib/bridgedb/Bridges.py index a60ff85..3ed1eff 100644 --- a/lib/bridgedb/Bridges.py +++ b/lib/bridgedb/Bridges.py @@ -23,10 +23,10 @@ import random import bridgedb.Storage import bridgedb.Bucket

-from bridgedb import util from bridgedb.crypto import getHMACFunc from bridgedb.parse import addr from bridgedb.parse import networkstatus +from bridgedb.safelog import logSafely

try: from cStringIO import StringIO @@ -1035,7 +1035,7 @@ class BridgeRing(BridgeHolder): else: logging.debug( "Got duplicate bridge %r in main hashring for position %r." - % (util.logSafely(k.encode('hex')), pos.encode('hex'))) + % (logSafely(k.encode('hex')), pos.encode('hex'))) keys = keys[:N] keys.sort()

@@ -1280,12 +1280,12 @@ class FilteredBridgeSplitter(BridgeHolder): if not bridge.running: logging.warn( "Skipping hashring insertion for non-running bridge: '%s'" - % util.logSafely(bridge.fingerprint)) + % logSafely(bridge.fingerprint)) return

index = 0 logging.debug("Inserting %s into splitter" - % (util.logSafely(bridge.fingerprint))) + % (logSafely(bridge.fingerprint))) for old_bridge in self.bridges[:]: if bridge.fingerprint == old_bridge.fingerprint: self.bridges[index] = bridge @@ -1297,7 +1297,7 @@ class FilteredBridgeSplitter(BridgeHolder): if filterFn(bridge): subring.insert(bridge) logging.debug("Inserted bridge '%s' into '%s' sub hashring" - % (util.logSafely(bridge.fingerprint), ringname)) + % (logSafely(bridge.fingerprint), ringname))

def extractFilterNames(self, ringname): """Get the names of the filters applied to a particular sub hashring. diff --git a/lib/bridgedb/Dist.py b/lib/bridgedb/Dist.py index c6e8756..38ca36d 100644 --- a/lib/bridgedb/Dist.py +++ b/lib/bridgedb/Dist.py @@ -22,13 +22,13 @@ from ipaddr import IPAddress import bridgedb.Bridges import bridgedb.Storage

-from bridgedb import util from bridgedb.crypto import getHMAC from bridgedb.crypto import getHMACFunc from bridgedb.Filters import filterAssignBridgesToRing from bridgedb.Filters import filterBridgesByRules from bridgedb.Filters import filterBridgesByIP4 from bridgedb.Filters import filterBridgesByIP6 +from bridgedb.safelog import logSafely

def uniformMap(ip): @@ -237,7 +237,7 @@ class IPBasedDistributor(Distributor): for an example of how this is used. """ logging.info("Attempting to return %d bridges to client %s..." - % (N, util.logSafely(ip))) + % (N, ip))

if not bridgeFilterRules: bridgeFilterRules=[] @@ -253,7 +253,7 @@ class IPBasedDistributor(Distributor):

area = self.areaMapper(ip) logging.debug("IP mapped to area:\t%s" - % util.logSafely("{0}.0/24".format(area))) + % logSafely("{0}.0/24".format(area)))

key1 = '' pos = 0 @@ -269,7 +269,7 @@ class IPBasedDistributor(Distributor): len(self.categories), n) bridgeFilterRules.append(g) - logging.info("category<%s>%s", epoch, util.logSafely(area)) + logging.info("category<%s>%s", epoch, logSafely(area)) pos = self.areaOrderHmac("category<%s>%s" % (epoch, area)) key1 = getHMAC(self.splitter.key, "Order-Bridges-In-Ring-%d" % n) @@ -477,8 +477,9 @@ class EmailBasedDistributor(Distributor): try: emailaddress = normalizeEmail(emailaddress, self.domainmap, self.domainrules) - except BadEmail: - return [] #XXXX log the exception + except BadEmail as err: + logging.warn(err) + return [] if emailaddress is None: return [] #XXXX raise an exception.

@@ -487,19 +488,17 @@ class EmailBasedDistributor(Distributor): lastSaw = db.getEmailTime(emailaddress)

logging.info("Attempting to return for %d bridges for %s..." - % (N, util.logSafely(emailaddress))) + % (N, emailaddress))

if lastSaw is not None and lastSaw + MAX_EMAIL_RATE >= now: logging.info("Client %s sent duplicate request within %d seconds." - % (util.logSafely(emailaddress), MAX_EMAIL_RATE)) + % (emailaddress, MAX_EMAIL_RATE)) if wasWarned: logging.info( "Client was already warned about duplicate requests.") - raise IgnoreEmail("Client was warned", - util.logSafely(emailaddress)) + raise IgnoreEmail("Client was warned", emailaddress) else: - logging.info("Sending duplicate request warning to %s..." - % util.logSafely(emailaddress)) + logging.info("Sending duplicate request warning.") db.setWarnedEmail(emailaddress, True, now) db.commit()

diff --git a/lib/bridgedb/EmailServer.py b/lib/bridgedb/EmailServer.py index 599b446..f9f43bb 100644 --- a/lib/bridgedb/EmailServer.py +++ b/lib/bridgedb/EmailServer.py @@ -26,10 +26,10 @@ from twisted.mail import smtp

from zope.interface import implements

-import bridgedb.util as util from bridgedb.Dist import BadEmail, TooSoonEmail, IgnoreEmail from bridgedb import Dist from bridgedb import I18n +from bridgedb import safelog from bridgedb.Filters import filterBridgesByIP6 from bridgedb.Filters import filterBridgesByIP4 from bridgedb.Filters import filterBridgesByTransport @@ -104,13 +104,13 @@ def getMailResponse(lines, ctx): return None, None

if not addrdomain: - logging.info("Couldn't parse domain from %r", util.logSafely(clientAddr)) + logging.info("Couldn't parse domain from %r" % clientAddr)

if addrdomain and ctx.cfg.EMAIL_DOMAIN_MAP: addrdomain = ctx.cfg.EMAIL_DOMAIN_MAP.get(addrdomain, addrdomain)

if addrdomain not in ctx.cfg.EMAIL_DOMAINS: - logging.info("Unrecognized email domain %r", util.logSafely(addrdomain)) + logging.warn("Unrecognized email domain %r", addrdomain) return None, None

rules = ctx.cfg.EMAIL_DOMAIN_RULES.get(addrdomain, []) @@ -188,7 +188,7 @@ def getMailResponse(lines, ctx): # Handle rate limited email except TooSoonEmail as err: logging.info("Got a mail too frequently; warning '%s': %s." - % (util.logSafely(clientAddr), err)) + % (clientAddr, err))

# Compose a warning email # MAX_EMAIL_RATE is in seconds, convert to hours @@ -198,12 +198,12 @@ def getMailResponse(lines, ctx):

except IgnoreEmail as err: logging.info("Got a mail too frequently; ignoring '%s': %s." - % (util.logSafely(clientAddr), err)) + % (clientAddr, err)) return None, None

except BadEmail as err: logging.info("Got a mail from a bad email address '%s': %s." - % (util.logSafely(clientAddr), err)) + % (clientAddr, err)) return None, None

if bridges: @@ -273,8 +273,8 @@ def replyToMail(lines, ctx): sendToUser, response = getMailResponse(lines, ctx)

if response is None: - logging.debug("getMailResponse() said not to reply to %s, so I won't." - % util.logSafely(sendToUser)) + logging.debug("We don't really feel like talking to %s right now." + % sendToUser) return

response.seek(0) @@ -283,7 +283,7 @@ def replyToMail(lines, ctx): factory = smtp.SMTPSenderFactory(ctx.smtpFromAddr, sendToUser, response, d, retries=0, timeout=30) d.addErrback(_ebReplyToMailFailure) - logging.info("Sending reply to %r", util.logSafely(sendToUser)) + logging.info("Sending reply to %s" % sendToUser) reactor.connectTCP(ctx.smtpServer, ctx.smtpPort, factory) return d

@@ -355,7 +355,7 @@ class MailMessage(object): def lineReceived(self, line): """Called when we get another line of an incoming message.""" self.nBytes += len(line) - if not util.safe_logging: + if not safelog.safe_logging: logging.debug("> %s", line.rstrip("\r\n")) if self.nBytes > self.ctx.maximumSize: self.ignoring = True @@ -467,11 +467,11 @@ def composeEmail(fromAddr, clientAddr, subject, body, msgID=False,

# Only log the email text (including all headers) if SAFE_LOGGING is # disabled: - if not util.safe_logging: + if not safelog.safe_logging: mail.seek(0) logging.debug("Email contents:\n%s" % mail.read()) else: - logging.debug("Email text for %r created." % util.logSafely(clientAddr)) + logging.debug("Email text for %r created." % clientAddr) mail.seek(0)

return clientAddr, mail diff --git a/lib/bridgedb/HTTPServer.py b/lib/bridgedb/HTTPServer.py index 06ae2ed..f460ac9 100644 --- a/lib/bridgedb/HTTPServer.py +++ b/lib/bridgedb/HTTPServer.py @@ -36,12 +36,12 @@ import bridgedb.I18n as I18n from bridgedb import captcha from bridgedb import crypto from bridgedb import txrecaptcha -from bridgedb import util from bridgedb.Filters import filterBridgesByIP4 from bridgedb.Filters import filterBridgesByIP6 from bridgedb.Filters import filterBridgesByTransport from bridgedb.Filters import filterBridgesByNotBlockedIn from bridgedb.parse import headers +from bridgedb.safelog import logSafely

@@ -289,8 +289,8 @@ class GimpCaptchaProtectedResource(CaptchaProtectedResource): clientHMACKey = crypto.getHMAC(self.hmacKey, clientIP) valid = captcha.GimpCaptcha.check(challenge, solution, self.secretKey, clientHMACKey) - logging.debug("%sorrect captcha from %r: %r." % ( - "C" if valid else "Inc", util.logSafely(clientIP), solution)) + logging.debug("%sorrect captcha from %r: %r." + % ("C" if valid else "Inc", clientIP, solution))

return valid

@@ -466,7 +466,7 @@ class ReCaptchaProtectedResource(CaptchaProtectedResource): remoteIP = self.getRemoteIP()

logging.debug("Captcha from %r. Parameters: %r" - % (util.logSafely(clientIP), request.args)) + % (clientIP, request.args))

def checkResponse(solution, request): """Check the :class:`txrecaptcha.RecaptchaResponse`. @@ -481,12 +481,11 @@ class ReCaptchaProtectedResource(CaptchaProtectedResource): # require networking (as well as automated CAPTCHA # breaking). Hence, the 'no cover' pragma. if solution.is_valid: # pragma: no cover - logging.info("Valid CAPTCHA solution from %r." - % util.logSafely(clientIP)) + logging.info("Valid CAPTCHA solution from %r." % clientIP) return (True, request) else: logging.info("Invalid CAPTCHA solution from %r: %r" - % (util.logSafely(clientIP), solution.error_code)) + % (clientIP, solution.error_code)) return (False, request)

d = txrecaptcha.submit(challenge, response, self.recaptchaPrivKey, @@ -672,7 +671,7 @@ class WebResourceBridges(resource.Resource): unblocked = False

logging.info("Replying to web request from %s. Parameters were %r" - % (util.logSafely(ip), request.args)) + % (ip, request.args))

rules = [] bridgeLines = None diff --git a/lib/bridgedb/Main.py b/lib/bridgedb/Main.py index 379c775..e29e991 100644 --- a/lib/bridgedb/Main.py +++ b/lib/bridgedb/Main.py @@ -20,6 +20,7 @@ from twisted.internet import reactor

from bridgedb import crypto from bridgedb import persistent +from bridgedb import safelog from bridgedb import util from bridgedb.parse import options

@@ -40,7 +41,7 @@ def configureLogging(cfg): logfile = getattr(cfg, 'LOGFILE', "") logfile_count = getattr(cfg, 'LOGFILE_COUNT', 5) logfile_rotate_size = getattr(cfg, 'LOGFILE_ROTATE_SIZE', 10000000) - util.set_safe_logging(safelogging) + safelog.setSafeLogging(safelogging)

logging.getLogger().setLevel(level) if logfile: @@ -238,9 +239,9 @@ def loadConfig(configFile=None, configCls=None): .. _faster: http://lucumr.pocoo.org/2011/2/1/exec-in-python/

:ivar boolean itsSafeToUseLogging: This is called in :func:`startup` - before :func:`configureLogging`. When called from ``startup``, the - ``configCls`` parameter is not given, because that is the first time - that a :class:`Conf` is created. If a :class:`logging.Logger` is + before :func:`safelog.configureLogging`. When called from ``startup``, + the ``configCls`` parameter is not given, because that is the first + time that a :class:`Conf` is created. If a :class:`logging.Logger` is created in this function, then logging will not be correctly configured, therefore, if the ``configCls`` parameter is not given, then it's the first time this function has been called and it is @@ -456,10 +457,10 @@ def startup(options):

# Set up logging as early as possible. We cannot import from the bridgedb # package any of our modules which import :mod:`logging` and start using - # it, at least, not until :func:`configureLogging` is 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. + # it, at least, not until :func:`safelog.configureLogging` is + # 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)

if options['dump-bridges'] or (options.subCommand is not None): diff --git a/lib/bridgedb/safelog.py b/lib/bridgedb/safelog.py index dac65f8..eb6810b 100644 --- a/lib/bridgedb/safelog.py +++ b/lib/bridgedb/safelog.py @@ -32,6 +32,7 @@ Module Overview: :: safelog | + |_setSafeLogging - Enable or disable safelogging globally. |_logSafely - Utility for manually sanitising a portion of a log message | |_BaseSafelogFilter - Base class for log message sanitisation filters diff --git a/lib/bridgedb/util.py b/lib/bridgedb/util.py index 723ed8e..ebca7e1 100644 --- a/lib/bridgedb/util.py +++ b/lib/bridgedb/util.py @@ -11,14 +11,5 @@

"""Common utilities for BridgeDB."""

-safe_logging = True

-def set_safe_logging(safe): - global safe_logging - safe_logging = safe

-def logSafely(val): - if safe_logging: - return "[scrubbed]" - else: - return val