diff options
author | Kali Kaneko (leap communications) <kali@leap.se> | 2016-10-05 12:28:14 -0400 |
---|---|---|
committer | Kali Kaneko (leap communications) <kali@leap.se> | 2016-10-07 10:22:36 -0400 |
commit | 99b53c1714d302d7f0884e03b5c102081c483504 (patch) | |
tree | 82ac74e776a330338bf94563273aa4d33f578877 | |
parent | 4a471fb8b434d3df07c5de42fc41590b5d9fc5f5 (diff) |
[refactor] use new logger infrastructure
26 files changed, 223 insertions, 194 deletions
diff --git a/src/leap/bitmask/bonafide/_protocol.py b/src/leap/bitmask/bonafide/_protocol.py index 1112550f..622086f5 100644 --- a/src/leap/bitmask/bonafide/_protocol.py +++ b/src/leap/bitmask/bonafide/_protocol.py @@ -1,4 +1,4 @@ -# -*- coding: utf-8 -*- + # -*- coding: utf-8 -*- # _protocol.py # Copyright (C) 2014-2015 LEAP # @@ -28,12 +28,15 @@ from leap.common.config import get_path_prefix from twisted.cred.credentials import UsernamePassword from twisted.internet.defer import fail -from twisted.python import log +from twisted.logger import Logger # TODO [ ] enable-disable services # TODO [ ] read provider info +logger = Logger() + + COMMANDS = 'signup', 'authenticate', 'logout', 'stats' _preffix = get_path_prefix() @@ -78,7 +81,7 @@ class BonafideProtocol(object): # Service public methods def do_signup(self, full_id, password, invite=None, autoconf=False): - log.msg('SIGNUP for %s' % full_id) + logger.debug('SIGNUP for %s' % full_id) _, provider_id = config.get_username_and_provider(full_id) provider = config.Provider(provider_id, autoconf=autoconf) @@ -125,7 +128,7 @@ class BonafideProtocol(object): # TODO -- turn this into JSON response return str(_session.token), str(_session.uuid) - log.msg('AUTH for %s' % full_id) + logger.debug('AUTH for %s' % full_id) # XXX get deferred? session = self._get_session(provider, full_id, password) @@ -136,7 +139,7 @@ class BonafideProtocol(object): def do_logout(self, full_id): # XXX use the AVATAR here - log.msg('LOGOUT for %s' % full_id) + logger.debug('LOGOUT for %s' % full_id) if (full_id not in self._sessions or not self._sessions[full_id].is_authenticated): return fail(RuntimeError("There is no session for such user")) @@ -155,7 +158,7 @@ class BonafideProtocol(object): return users def do_change_password(self, full_id, current_password, new_password): - log.msg('Change password for %s' % full_id) + logger.debug('change password for %s' % full_id) if (full_id not in self._sessions or not self._sessions[full_id].is_authenticated): return fail(RuntimeError("There is no session for such user")) @@ -194,7 +197,7 @@ class BonafideProtocol(object): pass def do_stats(self): - log.msg('Calculating Bonafide Service STATS') + logger.debug('calculating Bonafide Service STATS') mem = resource.getrusage(resource.RUSAGE_SELF).ru_maxrss return {'sessions': len(self._sessions), 'mem': '%s KB' % (mem / 1024)} diff --git a/src/leap/bitmask/bonafide/config.py b/src/leap/bitmask/bonafide/config.py index e4e2bf46..bf16d306 100644 --- a/src/leap/bitmask/bonafide/config.py +++ b/src/leap/bitmask/bonafide/config.py @@ -28,7 +28,7 @@ from urlparse import urlparse from twisted.internet import defer, reactor from twisted.internet.ssl import ClientContextFactory -from twisted.python import log +from twisted.logger import Logger from twisted.web.client import Agent, downloadPage from leap.bitmask.bonafide._http import httpRequest @@ -38,7 +38,8 @@ from leap.bitmask.bonafide.errors import NotConfiguredError, NetworkError from leap.common.check import leap_assert from leap.common.config import get_path_prefix as common_get_path_prefix from leap.common.files import mkdir_p -# check_and_fix_urw_only, get_mtime + +logger = Logger() APPNAME = "bonafide" @@ -189,14 +190,15 @@ class Provider(object): if not is_configured: if autoconf: - log.msg('provider %s not configured: downloading files...' % - domain) + logger.debug( + 'provider %s not configured: downloading files...' % + domain) self.bootstrap() else: raise NotConfiguredError("Provider %s is not configured" % (domain,)) else: - log.msg('Provider already initialized') + logger.debug('provider already initialized') self.first_bootstrap[self._domain] = defer.succeed( 'already_initialized') self.ongoing_bootstrap[self._domain] = defer.succeed( @@ -233,10 +235,10 @@ class Provider(object): def bootstrap(self): domain = self._domain - log.msg("Bootstrapping provider %s" % domain) + logger.debug("bootstrapping provider %s" % domain) ongoing = self.ongoing_bootstrap.get(domain) if ongoing: - log.msg('already bootstrapping this provider...') + logger.debug('already bootstrapping this provider...') return self.first_bootstrap[self._domain] = defer.Deferred() @@ -341,7 +343,7 @@ class Provider(object): # See: # https://leap.se/code/issues/7906 def further_bootstrap_needs_auth(ignored): - log.err('cannot download services config yet, need auth') + logger.warning('cannot download services config yet, need auth') pending_deferred = defer.Deferred() self.stuck_bootstrap[self._domain] = pending_deferred return pending_deferred @@ -364,8 +366,8 @@ class Provider(object): def workaround_for_config_fetch(failure): # FIXME --- configs.json raises 500, see #7914. # This is a workaround until that's fixed. - log.err(failure) - log.msg( + logger.error(failure) + logger.debug( "COULD NOT VERIFY CONFIGS.JSON, WORKAROUND: DIRECT DOWNLOAD") if 'mx' in self._provider_config.services: @@ -394,7 +396,7 @@ class Provider(object): if stuck: d = self._get_config_for_all_services(session) d.addCallback(lambda _: stuck.callback('continue!')) - d.addErrback(log.err) + d.addErrback(logger.err) return d if not self.has_fetched_services_config(): @@ -479,7 +481,7 @@ class Provider(object): def _load_provider_json(self): path = self._get_provider_json_path() if not is_file(path): - log.msg("Cannot LOAD provider config path %s" % path) + logger.debug("cannot LOAD provider config path %s" % path) return with open(path, 'r') as config: @@ -517,7 +519,7 @@ class Provider(object): return services_dict def _fetch_provider_configs_unauthenticated(self, uri, path): - log.msg('Downloading config for %s...' % uri) + logger.info('downloading config for %s...' % uri) d = downloadPage(uri, path, method='GET') return d diff --git a/src/leap/bitmask/bonafide/service.py b/src/leap/bitmask/bonafide/service.py index 4e25172c..0cd1053c 100644 --- a/src/leap/bitmask/bonafide/service.py +++ b/src/leap/bitmask/bonafide/service.py @@ -26,9 +26,10 @@ from leap.common.service_hooks import HookableService from leap.bitmask.bonafide._protocol import BonafideProtocol from twisted.internet import defer -from twisted.python import log +from twisted.logger import Logger +logger = Logger() _preffix = get_path_prefix() @@ -46,7 +47,7 @@ class BonafideService(HookableService): self._active_user = None def startService(self): - log.msg('Starting Bonafide Service') + logger.debug('starting Bonafide Service') super(BonafideService, self).startService() # Commands @@ -59,8 +60,8 @@ class BonafideService(HookableService): def notify_bonafide_auth(result): if not result: - msg = "Authentication hook did not return anything" - log.msg(msg) + msg = "authentication hook did not return anything" + logger.debug(msg) raise RuntimeError(msg) token, uuid = result diff --git a/src/leap/bitmask/bonafide/session.py b/src/leap/bitmask/bonafide/session.py index 213e7731..5a743e94 100644 --- a/src/leap/bitmask/bonafide/session.py +++ b/src/leap/bitmask/bonafide/session.py @@ -18,12 +18,14 @@ LEAP Session management. """ from twisted.internet import defer, reactor -from twisted.python import log +from twisted.logger import Logger from leap.bitmask.bonafide import _srp from leap.bitmask.bonafide import provider from leap.bitmask.bonafide._http import httpRequest, cookieAgentFactory +logger = Logger() + OK = 'ok' @@ -88,7 +90,7 @@ class Session(object): def authenticate(self): uri = self._api.get_handshake_uri() met = self._api.get_handshake_method() - log.msg("%s to %s" % (met, uri)) + logger.debug("%s to %s" % (met, uri)) params = self._srp_auth.get_handshake_params() handshake = yield self._request(self._agent, uri, values=params, @@ -98,7 +100,7 @@ class Session(object): uri = self._api.get_authenticate_uri(login=self.username) met = self._api.get_authenticate_method() - log.msg("%s to %s" % (met, uri)) + logger.debug("%s to %s" % (met, uri)) params = self._srp_auth.get_authentication_params() auth = yield self._request(self._agent, uri, values=params, @@ -215,8 +217,7 @@ if __name__ == "__main__": reactor.stop() def auth_eb(failure): - print "[ERROR!]", failure.getErrorMessage() - log.err(failure) + logger.error(failure) d = session.authenticate() d.addCallback(print_result) diff --git a/src/leap/bitmask/core/_zmq.py b/src/leap/bitmask/core/_zmq.py index a656fc65..30ac743d 100644 --- a/src/leap/bitmask/core/_zmq.py +++ b/src/leap/bitmask/core/_zmq.py @@ -20,7 +20,7 @@ ZMQ REQ-REP Dispatcher. from twisted.application import service from twisted.internet import reactor -from twisted.python import log +from twisted.logger import Logger from txzmq import ZmqEndpoint, ZmqEndpointType from txzmq import ZmqFactory, ZmqREPConnection @@ -29,6 +29,9 @@ from leap.bitmask.core import ENDPOINT from leap.bitmask.core.dispatcher import CommandDispatcher +logger = Logger() + + class ZMQServerService(service.Service): def __init__(self, core): @@ -61,8 +64,8 @@ class _DispatcherREPConnection(ZmqREPConnection): reactor.callLater(0, self.reply, msgId, str(response)) def log_err(self, failure, msgId): - log.err(failure) + logger.error(failure) self.defer_reply("ERROR: %r" % failure, msgId) def do_greet(self): - log.msg('starting ZMQ dispatcher') + logger.info('starting ZMQ dispatcher') diff --git a/src/leap/bitmask/core/dispatcher.py b/src/leap/bitmask/core/dispatcher.py index 5b7b836e..6a5603e6 100644 --- a/src/leap/bitmask/core/dispatcher.py +++ b/src/leap/bitmask/core/dispatcher.py @@ -25,7 +25,8 @@ except ImportError: from queue import Queue from twisted.internet import defer -from twisted.python import failure, log +from twisted.python import failure +from twisted.logger import Logger from leap.common.events import register_async as register from leap.common.events import unregister_async as unregister @@ -34,6 +35,9 @@ from leap.common.events import catalog from .api import APICommand, register_method +logger = Logger() + + class SubCommand(object): __metaclass__ = APICommand @@ -461,5 +465,6 @@ def _format_result(result): def _format_error(failure): - log.err(failure) + # TODO --- should check if the failure has the 'expected' attribute set + logger.failure('[DISPATCHER] Uncatched error:') return json.dumps({'error': failure.value.message, 'result': None}) diff --git a/src/leap/bitmask/core/mail_services.py b/src/leap/bitmask/core/mail_services.py index 8e3a35d9..bd7f5579 100644 --- a/src/leap/bitmask/core/mail_services.py +++ b/src/leap/bitmask/core/mail_services.py @@ -31,7 +31,7 @@ from twisted.application import service from twisted.internet import defer from twisted.internet import reactor from twisted.internet import task -from twisted.python import log +from twisted.logger import Logger # TODO move to bitmask.common from leap.common.service_hooks import HookableService @@ -53,6 +53,9 @@ from leap.bitmask.core.uuid_map import UserMap from leap.bitmask.core.configurable import DEFAULT_BASEDIR +logger = Logger() + + class Container(object): def __init__(self, service=None): @@ -165,7 +168,7 @@ class SoledadService(HookableService): self._basedir = basedir def startService(self): - log.msg('Starting Soledad Service') + logger.info('starting Soledad Service') self._container = SoledadContainer(service=self) super(SoledadService, self).startService() @@ -182,11 +185,11 @@ class SoledadService(HookableService): password = kw.get('password') uuid = kw.get('uuid') container = self._container - log.msg("on_passphrase_entry: New Soledad Instance: %s" % userid) + logger.debug("on_passphrase_entry: New Soledad Instance: %s" % userid) if not container.get_instance(userid): container.add_instance(userid, password, uuid=uuid, token=None) else: - log.msg('Service MX is not ready...') + logger.debug('service MX is not ready...') def hook_on_bonafide_auth(self, **kw): userid = kw['username'] @@ -202,11 +205,11 @@ class SoledadService(HookableService): container = self._container if container.get_instance(userid): - log.msg("Passing a new SRP Token to Soledad: %s" % userid) + logger.debug("passing a new SRP Token to Soledad: %s" % userid) container.set_remote_auth_token(userid, token) container.set_syncable(userid, True) else: - log.msg("Adding a new Soledad Instance: %s" % userid) + logger.debug("adding a new Soledad Instance: %s" % userid) container.add_instance( userid, password, uuid=uuid, token=token) @@ -218,7 +221,7 @@ class SoledadService(HookableService): password = kw['password'] soledad = self._container.get_instance(userid) if soledad is not None: - log.msg("Change soledad passphrase for %s" % userid) + logger.info("Change soledad passphrase for %s" % userid) soledad.change_passphrase(unicode(password)) @@ -229,7 +232,7 @@ class KeymanagerContainer(Container): super(KeymanagerContainer, self).__init__(service=service) def add_instance(self, userid, token, uuid, soledad): - log.msg("Adding Keymanager instance for: %s" % userid) + logger.debug("adding Keymanager instance for: %s" % userid) keymanager = self._create_keymanager_instance( userid, token, uuid, soledad) super(KeymanagerContainer, self).add_instance(userid, keymanager) @@ -247,15 +250,15 @@ class KeymanagerContainer(Container): def _get_or_generate_keys(self, keymanager, userid): def _get_key(_): - log.msg("looking up private key for %s" % userid) + logger.info("looking up private key for %s" % userid) return keymanager.get_key(userid, private=True, fetch_remote=False) def _found_key(key): - log.msg("found key: %r" % key) + logger.info("found key: %r" % key) def _if_not_found_generate(failure): failure.trap(KeyNotFound) - log.msg("key not found, generating key for %s" % (userid,)) + logger.info("key not found, generating key for %s" % (userid,)) d = keymanager.gen_key() d.addCallbacks(_send_key, _log_key_error("generating")) return d @@ -266,43 +269,43 @@ class KeymanagerContainer(Container): # but this hasn't been successfully uploaded. How do we know that? # XXX Should this be a method of bonafide instead? # ----------------------------------------------------------------- - log.msg("key generated for %s" % userid) + logger.info("key generated for %s" % userid) if not keymanager.token: - log.msg("token not available, scheduling new send attempt...") + logger.debug("token not available, scheduling new send attempt...") return task.deferLater(reactor, 5, _send_key, None) - log.msg("sending public key to server") + logger.info("sending public key to server") d = keymanager.send_key() d.addCallbacks( - lambda _: log.msg("key sent to server"), + lambda _: logger.info("key sent to server"), _log_key_error("sending")) return d def _log_key_error(step): def log_error(failure): - log.err("Error while %s key!" % step) - log.err(failure) + logger.err("Error while %s key!" % step) + logger.err(failure) return failure return log_error def _sync_if_never_synced(ever_synced): if ever_synced: - log.msg("soledad has synced in the past") + logger.debug("soledad has synced in the past") return defer.succeed(None) - log.msg("soledad has never synced") + logger.debug("soledad has never synced") if not keymanager.token: - log.msg("no token to sync now, scheduling a new check") + logger.debug("no token to sync now, scheduling a new check") d = task.deferLater(reactor, 5, keymanager.ever_synced) d.addCallback(_sync_if_never_synced) return d - log.msg("syncing soledad for the first time...") + logger.debug("syncing soledad for the first time...") return keymanager._soledad.sync() - log.msg("checking if soledad has ever synced...") + logger.debug("checking if soledad has ever synced...") d = keymanager.ever_synced() d.addCallback(_sync_if_never_synced) d.addCallback(_get_key) @@ -347,9 +350,10 @@ class KeymanagerService(HookableService): def __init__(self, basedir=DEFAULT_BASEDIR): service.Service.__init__(self) self._basedir = basedir + self._container = None def startService(self): - log.msg('Starting Keymanager Service') + logger.debug('starting Keymanager Service') self._container = KeymanagerContainer(self._basedir) self._container.service = self self.tokens = {} @@ -364,7 +368,7 @@ class KeymanagerService(HookableService): uuid = kw['uuid'] soledad = kw['soledad'] if not container.get_instance(user): - log.msg('Adding a new Keymanager instance for %s' % user) + logger.debug('Adding a new Keymanager instance for %s' % user) if not token: token = self.tokens.get(user) container.add_instance(user, token, uuid, soledad) @@ -381,10 +385,10 @@ class KeymanagerService(HookableService): container = self._container if container.get_instance(userid): - log.msg('Passing a new SRP Token to Keymanager: %s' % userid) + logger.debug('Passing a new SRP Token to Keymanager: %s' % userid) container.set_remote_auth_token(userid, token) else: - log.msg('storing the keymanager token... %s ' % token) + logger.debug('storing the keymanager token... %s ' % token) self.tokens[userid] = token # commands @@ -455,11 +459,11 @@ class StandardMailService(service.MultiService, HookableService): self.addService(IncomingMailService(self)) def startService(self): - log.msg('starting mail service') + logger.info('starting mail service') super(StandardMailService, self).startService() def stopService(self): - log.msg('stopping mail service') + logger.info('stopping mail service') super(StandardMailService, self).stopService() def startInstance(self, userid, soledad, keymanager): @@ -504,7 +508,7 @@ class StandardMailService(service.MultiService, HookableService): # turn on incoming mail service for the user that just logged in multiservice = self.getServiceNamed('incoming_mail') incoming = multiservice.getServiceNamed(userid) - log.msg('looking for incoming mail service for auth: %s' % userid) + logger.debug('looking for incoming mail service for auth: %s' % userid) if incoming: incoming.startService() @@ -530,7 +534,7 @@ class StandardMailService(service.MultiService, HookableService): username = kw['username'] multiservice = self.getServiceNamed('incoming_mail') incoming = multiservice.getServiceNamed(username) - log.msg('looking for incoming mail service for logout: %s' % username) + logger.debug('looking for incoming mail service for logout: %s' % username) if incoming: incoming.stopService() @@ -561,8 +565,8 @@ class StandardMailService(service.MultiService, HookableService): try: shutil.rmtree(tokens_folder) except OSError as e: - log.msg("Can't remove tokens folder %s: %s" - % (tokens_folder, e)) + logger.warning("Can't remove tokens folder %s: %s" + % (tokens_folder, e)) return os.mkdir(tokens_folder, 0700) @@ -584,7 +588,7 @@ class IMAPService(service.Service): super(IMAPService, self).__init__() def startService(self): - log.msg('starting imap service') + logger.info('starting imap service') port, factory = imap_service.run_service( self._soledad_sessions, factory=self._factory) self._port = port @@ -592,7 +596,7 @@ class IMAPService(service.Service): super(IMAPService, self).startService() def stopService(self): - log.msg("stopping imap service") + logger.info("stopping imap service") if self._port: self._port.stopListening() self._port = None @@ -617,7 +621,7 @@ class SMTPService(service.Service): super(SMTPService, self).__init__() def startService(self): - log.msg('starting smtp service') + logger.info('starting smtp service') port, factory = smtp_service.run_service( self._soledad_sessions, self._keymanager_sessions, @@ -628,7 +632,7 @@ class SMTPService(service.Service): super(SMTPService, self).startService() def stopService(self): - log.msg('stopping smtp service') + logger.info('stopping smtp service') if self._port: self._port.stopListening() self._port = None @@ -649,7 +653,7 @@ class IncomingMailService(service.MultiService): self._mail = mail_service def startService(self): - log.msg('starting incoming mail service') + logger.info('starting incoming mail service') super(IncomingMailService, self).startService() def stopService(self): @@ -661,7 +665,7 @@ class IncomingMailService(service.MultiService): soledad = self._mail.get_soledad_session(userid) keymanager = self._mail.get_keymanager_session(userid) - log.msg('setting up incoming mail service for %s' % userid) + logger.info('setting up incoming mail service for %s' % userid) self._start_incoming_mail_instance( keymanager, soledad, userid) @@ -680,7 +684,7 @@ class IncomingMailService(service.MultiService): d = acc.callWhenReady( lambda _: acc.get_collection_by_mailbox(INBOX_NAME)) d.addCallback(setUpIncomingMail) - d.addErrback(log.err) + d.addErrback(logger.err) return d # -------------------------------------------------------------------- diff --git a/src/leap/bitmask/core/service.py b/src/leap/bitmask/core/service.py index 1a544acf..5718178c 100644 --- a/src/leap/bitmask/core/service.py +++ b/src/leap/bitmask/core/service.py @@ -21,7 +21,7 @@ import json import resource from twisted.internet import reactor -from twisted.python import log +from twisted.logger import Logger from leap.bitmask import __version__ from leap.bitmask.core import configurable @@ -31,6 +31,8 @@ from leap.bitmask.core import flags from leap.common.events import server as event_server # from leap.vpn import EIPService +logger = Logger() + backend = flags.BACKEND @@ -92,13 +94,13 @@ class BitmaskBackend(configurable.ConfigurableService): bf.register_hook('on_bonafide_logout', listener='mail') def _start_child_service(self, name): - log.msg('starting backend child service: %s' % name) + logger.debug('starting backend child service: %s' % name) service = self.getServiceNamed(name) if service: service.startService() def _stop_child_service(self, name): - log.msg('stopping backend child service: %s' % name) + logger.debug('stopping backend child service: %s' % name) service = self.getServiceNamed(name) if service: service.stopService() @@ -159,7 +161,7 @@ class BitmaskBackend(configurable.ConfigurableService): try: service = self.getServiceNamed(label) except KeyError: - log.msg("initializing service: %s" % label) + logger.debug("initializing service: %s" % label) service = klass(*args, **kw) service.setName(label) service.setServiceParent(self) @@ -238,7 +240,7 @@ class BackendCommands(object): return {'version_core': __version__} def do_stats(self): - log.msg('BitmaskCore Service STATS') + logger.debug('BitmaskCore Service STATS') mem = resource.getrusage(resource.RUSAGE_SELF).ru_maxrss return {'mem_usage': '%s MB' % (mem / 1024)} diff --git a/src/leap/bitmask/keymanager/__init__.py b/src/leap/bitmask/keymanager/__init__.py index 146bcd2f..aafb9ce0 100644 --- a/src/leap/bitmask/keymanager/__init__.py +++ b/src/leap/bitmask/keymanager/__init__.py @@ -25,15 +25,14 @@ import tempfile import json import urllib -from leap.common import ca_bundle -from twisted.web import client -from twisted.web._responses import NOT_FOUND - -import logging +from urlparse import urlparse +from twisted.logger import Logger from twisted.internet import defer -from urlparse import urlparse +from twisted.web import client +from twisted.web._responses import NOT_FOUND +from leap.common import ca_bundle from leap.common.check import leap_assert from leap.common.http import HTTPClient from leap.common.events import emit_async, catalog @@ -47,7 +46,7 @@ from leap.bitmask.keymanager.errors import ( from leap.bitmask.keymanager.validation import ValidationLevels, can_upgrade from leap.bitmask.keymanager.openpgp import OpenPGPScheme -logger = logging.getLogger(__name__) +logger = Logger() # @@ -144,15 +143,15 @@ class KeyManager(object): except KeyNotFound: raise except IOError as e: - logger.warning("HTTP error retrieving key: %r" % (e,)) - logger.warning("%s" % (content,)) + logger.warn("HTTP error retrieving key: %r" % (e,)) + logger.warn("%s" % (content,)) raise KeyNotFound(e.message), None, sys.exc_info()[2] except ValueError as v: - logger.warning("Invalid JSON data from key: %s" % (uri,)) + logger.warn("invalid JSON data from key: %s" % (uri,)) raise KeyNotFound(v.message + ' - ' + uri), None, sys.exc_info()[2] except Exception as e: - logger.warning("Error retrieving key: %r" % (e,)) + logger.warn("error retrieving key: %r" % (e,)) raise KeyNotFound(e.message), None, sys.exc_info()[2] # Responses are now text/plain, although it's json anyway, but # this will fail when it shouldn't @@ -176,7 +175,7 @@ class KeyManager(object): def check_404(response): if response.code == NOT_FOUND: message = '%s: %s key not found.' % (response.code, address) - logger.warning(message) + logger.warn(message) raise KeyNotFound(message), None, sys.exc_info()[2] return response @@ -204,7 +203,7 @@ class KeyManager(object): try: content = yield self._async_client.request(str(uri), 'GET') except Exception as e: - logger.warning("There was a problem fetching key: %s" % (e,)) + logger.warn("There was a problem fetching key: %s" % (e,)) raise KeyNotFound(uri) if not content: raise KeyNotFound(uri) @@ -239,12 +238,12 @@ class KeyManager(object): body=str(data), headers=headers) except Exception as e: - logger.warning("Error uploading key: %r" % (e,)) + logger.warn("Error uploading key: %r" % (e,)) raise e if 'error' in res: # FIXME: That's a workaround for 500, # we need to implement a readBody to assert response code - logger.warning("Error uploading key: %r" % (res,)) + logger.warn("Error uploading key: %r" % (res,)) raise Exception(res) @memoized_method(invalidation=300) @@ -759,7 +758,7 @@ class KeyManager(object): :raise UnsupportedKeyTypeError: if invalid key type """ - logger.info("Fetch key for %s from %s" % (address, uri)) + logger.info("fetch key for %s from %s" % (address, uri)) ascii_content = yield self._get_with_combined_ca_bundle(uri) # XXX parse binary keys diff --git a/src/leap/bitmask/keymanager/keys.py b/src/leap/bitmask/keymanager/keys.py index 2ea4c8e5..45a7d720 100644 --- a/src/leap/bitmask/keymanager/keys.py +++ b/src/leap/bitmask/keymanager/keys.py @@ -18,18 +18,19 @@ Abstact key type and encryption scheme representations. """ import json -import logging import re import time from datetime import datetime +from twisted.logger import Logger + from leap.bitmask.keymanager import errors from leap.bitmask.keymanager.wrapper import TempGPGWrapper from leap.bitmask.keymanager.validation import ValidationLevels from leap.bitmask.keymanager import documents as doc -logger = logging.getLogger(__name__) +logger = Logger() # diff --git a/src/leap/bitmask/keymanager/openpgp.py b/src/leap/bitmask/keymanager/openpgp.py index b07ac418..43c8d938 100644 --- a/src/leap/bitmask/keymanager/openpgp.py +++ b/src/leap/bitmask/keymanager/openpgp.py @@ -17,7 +17,6 @@ """ Infrastructure for using OpenPGP keys in Key Manager. """ -import logging import os import re import tempfile @@ -30,6 +29,7 @@ from multiprocessing import cpu_count from gnupg.gnupg import GPGUtilities from twisted.internet import defer from twisted.internet.threads import deferToThread +from twisted.logger import Logger from leap.common.check import leap_assert, leap_assert_type, leap_check from leap.bitmask.keymanager import errors @@ -61,7 +61,7 @@ from leap.bitmask.keymanager.documents import ( ) -logger = logging.getLogger(__name__) +logger = Logger() # @@ -497,8 +497,8 @@ class OpenPGPScheme(object): if len(docs) == 0: raise errors.KeyNotFound(key) elif len(docs) > 1: - logger.warning("There is more than one key for fingerprint %s" - % key.fingerprint) + logger.warn("There is more than one key for fingerprint %s" + % key.fingerprint) has_deleted = False deferreds = [] @@ -585,7 +585,7 @@ class OpenPGPScheme(object): self._assert_gpg_result_ok(result) defer.returnValue(result.data) except errors.GPGError as e: - logger.warning('Failed to encrypt: %s.' % str(e)) + logger.warn('Failed to encrypt: %s.' % str(e)) raise errors.EncryptError() @defer.inlineCallbacks @@ -631,7 +631,7 @@ class OpenPGPScheme(object): defer.returnValue((result.data, sign_valid)) except errors.GPGError as e: - logger.warning('Failed to decrypt: %s.' % str(e)) + logger.warn('Failed to decrypt: %s.' % str(e)) raise errors.DecryptError(str(e)) def is_encrypted(self, data): diff --git a/src/leap/bitmask/mail/adaptors/soledad.py b/src/leap/bitmask/mail/adaptors/soledad.py index 39c6bcb5..b8153e56 100644 --- a/src/leap/bitmask/mail/adaptors/soledad.py +++ b/src/leap/bitmask/mail/adaptors/soledad.py @@ -16,16 +16,14 @@ """ Soledadad MailAdaptor module. """ -import logging import re from collections import defaultdict from email import message_from_string from twisted.internet import defer -from twisted.python import log +from twisted.logger import Logger from zope.interface import implements -from leap.soledad.common import l2db from leap.common.check import leap_assert, leap_assert_type @@ -39,10 +37,11 @@ from leap.bitmask.mail.utils import lowerdict, first from leap.bitmask.mail.utils import stringify_parts_map from leap.bitmask.mail.interfaces import IMailAdaptor, IMessageWrapper +from leap.soledad.common import l2db from leap.soledad.common.document import SoledadDocument -logger = logging.getLogger(__name__) +logger = Logger() # TODO # [ ] Convenience function to create mail specifying subject, date, etc? @@ -187,7 +186,7 @@ class SoledadDocumentWrapper(models.DocumentWrapper): # error, we should mark them in the copy so there is no attempt to # create/update them. failure.trap(l2db.errors.RevisionConflict) - logger.debug("Got conflict while putting %s" % doc_id) + logger.debug("got conflict while putting %s" % doc_id) def delete(self, store): """ @@ -505,7 +504,7 @@ class MessageWrapper(object): for (key, doc) in cdocs.items()]) for doc_id, cdoc in zip(self.mdoc.cdocs, self.cdocs.values()): if cdoc.raw == "": - log.msg("Empty raw field in cdoc %s" % doc_id) + logger.warning("Empty raw field in cdoc %s" % doc_id) cdoc.set_future_doc_id(doc_id) def create(self, store, notify_just_mdoc=False, pending_inserts_dict=None): @@ -567,8 +566,8 @@ class MessageWrapper(object): mdoc_created = self.mdoc.create(store, is_copy=self._is_copy) fdoc_created = self.fdoc.create(store, is_copy=self._is_copy) - mdoc_created.addErrback(lambda f: log.err(f)) - fdoc_created.addErrback(lambda f: log.err(f)) + mdoc_created.addErrback(logger.error) + fdoc_created.addErrback(logger.error) self.d.append(mdoc_created) self.d.append(fdoc_created) @@ -584,13 +583,13 @@ class MessageWrapper(object): self.d.append(cdoc.create(store)) def log_all_inserted(result): - log.msg("All parts inserted for msg!") + logger.debug("All parts inserted for msg!") return result self.all_inserted_d = defer.gatherResults(self.d, consumeErrors=True) self.all_inserted_d.addCallback(log_all_inserted) self.all_inserted_d.addCallback(unblock_pending_insert) - self.all_inserted_d.addErrback(lambda failure: log.err(failure)) + self.all_inserted_d.addErrback(logger.error) if notify_just_mdoc: return mdoc_created @@ -639,7 +638,7 @@ class MessageWrapper(object): d = new_wrapper.create(store) d.addCallback(lambda result: new_wrapper) - d.addErrback(lambda failure: log.err(failure)) + d.addErrback(logger.error) return d def set_mbox_uuid(self, mbox_uuid): @@ -946,15 +945,15 @@ class SoledadMailAdaptor(SoledadIndexMixin): # See https://leap.se/code/issues/7495. # This avoids blocks, but the real cause still needs to be # isolated (0.9.0rc3) -- kali - log.msg("BUG ---------------------------------------------------") - log.msg("BUG: Error while retrieving part docs for mdoc id %s" % - mdoc_id) - log.err(failure) - log.msg("BUG (please report above info) ------------------------") + logger.debug("BUG ---------------------------------------------------") + logger.debug("BUG: Error while retrieving part docs for mdoc id %s" % + mdoc_id) + logger.error(failure) + logger.debug("BUG (please report above info) ------------------------") return [] def _err_log_cannot_find_msg(failure): - log.msg("BUG: Error while getting msg (uid=%s)" % uid) + logger.error("BUG: Error while getting msg (uid=%s)" % uid) return None if get_cdocs: @@ -1041,7 +1040,7 @@ class SoledadMailAdaptor(SoledadIndexMixin): Delete all messages flagged as deleted. """ def err(failure): - log.err(failure) + logger.errror(failure) def delete_fdoc_and_mdoc_flagged(fdocs): # low level here, not using the wrappers... @@ -1125,7 +1124,7 @@ class SoledadMailAdaptor(SoledadIndexMixin): def get_mdoc_id(hdoc): if not hdoc: - log.msg("Could not find a HDOC with MSGID %s" % msgid) + logger.warning("Could not find a HDOC with MSGID %s" % msgid) return None hdoc = hdoc[0] mdoc_id = hdoc.doc_id.replace("H-", "M-%s-" % uuid) @@ -1177,7 +1176,7 @@ class SoledadMailAdaptor(SoledadIndexMixin): return MailboxWrapper.get_all(store) def _errback(self, failure): - log.err(failure) + logger.error(failure) def _split_into_parts(raw): diff --git a/src/leap/bitmask/mail/imap/account.py b/src/leap/bitmask/mail/imap/account.py index d885d591..8ee0cbfa 100644 --- a/src/leap/bitmask/mail/imap/account.py +++ b/src/leap/bitmask/mail/imap/account.py @@ -17,14 +17,14 @@ """ Soledad Backed IMAP Account. """ -import logging import os import time from functools import partial from twisted.internet import defer +from twisted.logger import Logger from twisted.mail import imap4 -from twisted.python import log +from twisted.logger import Logger from zope.interface import implements from leap.common.check import leap_assert, leap_assert_type @@ -33,7 +33,7 @@ from leap.bitmask.mail.mail import Account from leap.bitmask.mail.imap.mailbox import IMAPMailbox, normalize_mailbox from leap.soledad.client import Soledad -logger = logging.getLogger(__name__) +logger = Logger() PROFILE_CMD = os.environ.get('LEAP_PROFILE_IMAPCMD', False) @@ -247,7 +247,7 @@ class IMAPAccount(object): def check_it_exists(mailboxes): if name not in mailboxes: - logger.warning("SELECT: No such mailbox!") + logger.warn('SELECT: No such mailbox!') return None return name diff --git a/src/leap/bitmask/mail/imap/mailbox.py b/src/leap/bitmask/mail/imap/mailbox.py index b80280c6..10ac01e4 100644 --- a/src/leap/bitmask/mail/imap/mailbox.py +++ b/src/leap/bitmask/mail/imap/mailbox.py @@ -18,7 +18,6 @@ IMAP Mailbox. """ import re -import logging import os import cStringIO import StringIO @@ -29,7 +28,7 @@ from email.utils import formatdate from twisted.internet import defer from twisted.internet import reactor -from twisted.python import log +from twisted.logger import Logger from twisted.mail import imap4 from zope.interface import implements @@ -39,7 +38,7 @@ from leap.common.check import leap_assert_type from leap.bitmask.mail.constants import INBOX_NAME, MessageFlags from leap.bitmask.mail.imap.messages import IMAPMessage -logger = logging.getLogger(__name__) +logger = Logger() # TODO LIST # [ ] Restore profile_cmd instrumentation @@ -894,7 +893,7 @@ class IMAPMailbox(object): return d # nothing implemented for any other query - logger.warning("Cannot process query: %s" % (query,)) + logger.warn("Cannot process query: %s" % (query,)) return [] # IMessageCopier diff --git a/src/leap/bitmask/mail/imap/messages.py b/src/leap/bitmask/mail/imap/messages.py index 841ebb2f..98d64fe5 100644 --- a/src/leap/bitmask/mail/imap/messages.py +++ b/src/leap/bitmask/mail/imap/messages.py @@ -17,15 +17,15 @@ """ IMAPMessage implementation. """ -import logging from twisted.mail import imap4 from twisted.internet import defer +from twisted.logger import Logger from zope.interface import implements from leap.bitmask.mail.utils import find_charset, CaseInsensitiveDict -logger = logging.getLogger(__name__) +logger = Logger() # TODO # [ ] Add ref to incoming message during add_msg. @@ -213,7 +213,7 @@ def _format_headers(headers, negate, *names): # some reason we do not have headers, we have to return at least that # one if not headers: - logger.warning("No headers found") + logger.warn("No headers found") return {str('content-type'): str('')} names = map(lambda s: s.upper(), names) diff --git a/src/leap/bitmask/mail/imap/server.py b/src/leap/bitmask/mail/imap/server.py index 5a63af01..897e1f05 100644 --- a/src/leap/bitmask/mail/imap/server.py +++ b/src/leap/bitmask/mail/imap/server.py @@ -22,7 +22,7 @@ from copy import copy from twisted.internet.defer import maybeDeferred from twisted.mail import imap4 -from twisted.python import log +from twisted.logger import Logger # imports for LITERAL+ patch from twisted.internet import defer, interfaces @@ -32,6 +32,9 @@ from twisted.mail.imap4 import LiteralString, LiteralFile from leap.common.events import emit_async, catalog +logger = Logger() + + def _getContentType(msg): """ Return a two-tuple of the main and subtype of the given message. @@ -164,7 +167,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): msg = line[:7] + " [...]" else: msg = copy(line) - log.msg('rcv (%s): %s' % (self.state, msg)) + logger.debug('rcv (%s): %s' % (self.state, msg)) imap4.IMAP4Server.lineReceived(self, line) def close_server_connection(self): @@ -449,7 +452,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): def _subscribeEb(failure): m = failure.value - log.err() + logger.error() if failure.check(imap4.MailboxException): self.sendNegativeResponse(tag, str(m)) else: @@ -474,7 +477,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): def _unsubscribeEb(failure): m = failure.value - log.err() + logger.error() if failure.check(imap4.MailboxException): self.sendNegativeResponse(tag, str(m)) else: @@ -509,7 +512,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): elif failure.check(imap4.MailboxException): self.sendNegativeResponse(tag, str(m)) else: - log.err() + logger.error() self.sendBadResponse( tag, "Server error encountered while " @@ -536,7 +539,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): if failure.check(imap4.MailboxException): self.sendNegativeResponse(tag, str(c)) else: - log.err() + logger.error() self.sendBadResponse( tag, "Server error encountered while creating mailbox") @@ -561,8 +564,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): if failure.check(imap4.MailboxException): self.sendNegativeResponse(tag, str(m)) else: - print "SERVER: other error" - log.err() + logger.error() self.sendBadResponse( tag, "Server error encountered while deleting mailbox") @@ -598,7 +600,7 @@ class LEAPIMAPServer(imap4.IMAP4Server): def _ebAppendGotMailbox(self, failure, tag): self.sendBadResponse( tag, "Server error encountered while opening mailbox.") - log.err(failure) + logger.error(failure) def __cbAppend(self, result, tag, mbox): diff --git a/src/leap/bitmask/mail/imap/service/__init__.py b/src/leap/bitmask/mail/imap/service/__init__.py index d9cd3359..b0ad05d2 100644 --- a/src/leap/bitmask/mail/imap/service/__init__.py +++ b/src/leap/bitmask/mail/imap/service/__init__.py @@ -17,18 +17,17 @@ """ IMAP Service Initialization. """ -import logging import os from collections import defaultdict from twisted.cred.portal import Portal, IRealm -from twisted.mail.imap4 import IAccount from twisted.internet import defer from twisted.internet import reactor from twisted.internet.error import CannotListenError from twisted.internet.protocol import ServerFactory -from twisted.python import log +from twisted.logger import Logger +from twisted.mail.imap4 import IAccount from zope.interface import implementer from leap.common.events import emit_async, catalog @@ -38,7 +37,7 @@ from leap.bitmask.mail.imap.server import LEAPIMAPServer # TODO: leave only an implementor of IService in here -logger = logging.getLogger(__name__) +logger = Logger() DO_MANHOLE = os.environ.get("LEAP_MAIL_MANHOLE", None) if DO_MANHOLE: diff --git a/src/leap/bitmask/mail/mail.py b/src/leap/bitmask/mail/mail.py index 7a16b461..30fbd497 100644 --- a/src/leap/bitmask/mail/mail.py +++ b/src/leap/bitmask/mail/mail.py @@ -24,7 +24,6 @@ In the future, pluggable transports will expose this generic API. """ import itertools import uuid -import logging import StringIO import time import weakref @@ -32,11 +31,10 @@ import weakref from collections import defaultdict from twisted.internet import defer -from twisted.python import log +from twisted.logger import Logger from leap.common.check import leap_assert_type from leap.common.events import emit_async, catalog - from leap.bitmask.mail.adaptors.soledad import SoledadMailAdaptor from leap.bitmask.mail.constants import INBOX_NAME from leap.bitmask.mail.constants import MessageFlags @@ -45,7 +43,7 @@ from leap.bitmask.mail.plugins import soledad_sync_hooks from leap.bitmask.mail.utils import find_charset, CaseInsensitiveDict from leap.bitmask.mail.utils import lowerdict -logger = logging.getLogger(name=__name__) +logger = Logger() # TODO LIST @@ -193,7 +191,7 @@ class MessagePart(object): try: part_map = sub_pmap[str(part)] except KeyError: - log.msg("getSubpart for %s: KeyError" % (part,)) + logger.debug("getSubpart for %s: KeyError" % (part,)) raise IndexError return MessagePart(part_map, cdocs=self._cdocs, nested=True) @@ -441,7 +439,7 @@ class MessageCollection(object): d.addCallback( lambda uid: self.get_message_by_uid( uid, get_cdocs=get_cdocs)) - d.addErrback(lambda f: log.err(f)) + d.addErrback(logger.error) return d def get_message_by_uid(self, uid, absolute=True, get_cdocs=False): @@ -614,7 +612,7 @@ class MessageCollection(object): headers = lowerdict(msg.get_headers()) moz_draft_hdr = "X-Mozilla-Draft-Info" if moz_draft_hdr.lower() in headers: - log.msg("Setting fast notify to False, Draft detected") + logger.debug("setting fast notify to False, Draft detected") notify_just_mdoc = False if notify_just_mdoc: @@ -659,7 +657,7 @@ class MessageCollection(object): d.addCallback(insert_mdoc_id, wrapper) d.addCallback(self.cb_signal_unread_to_ui) d.addCallback(self.notify_new_to_listeners) - d.addErrback(lambda failure: log.err(failure)) + d.addErrback(logger.error) return d @@ -746,7 +744,7 @@ class MessageCollection(object): def insert_doc(_, mbox_uuid, doc_id): d = self.mbox_indexer.get_uid_from_doc_id(mbox_uuid, doc_id) d.addCallback(insert_conditionally, mbox_uuid, doc_id) - d.addErrback(lambda err: log.failure(err)) + d.addErrback(logger.error) d.addCallback(log_result) return d @@ -804,7 +802,7 @@ class MessageCollection(object): self.store, self.mbox_uuid) mdocs_deleted.addCallback(get_uid_list) mdocs_deleted.addCallback(delete_uid_entries) - mdocs_deleted.addErrback(lambda f: log.err(f)) + mdocs_deleted.addErrback(logger.error) return mdocs_deleted # TODO should add a delete-by-uid to collection? diff --git a/src/leap/bitmask/mail/outgoing/service.py b/src/leap/bitmask/mail/outgoing/service.py index 9fe3ec1b..f483763a 100644 --- a/src/leap/bitmask/mail/outgoing/service.py +++ b/src/leap/bitmask/mail/outgoing/service.py @@ -35,8 +35,8 @@ from OpenSSL import SSL from twisted.mail import smtp from twisted.internet import reactor from twisted.internet import defer +from twisted.logger import Logger from twisted.protocols.amp import ssl -from twisted.python import log from leap.common.check import leap_assert_type, leap_assert from leap.common.events import emit_async, catalog @@ -55,6 +55,11 @@ from leap.bitmask.mail.rfc3156 import PGPEncrypted # [ ] rename this module to something else, service should be the implementor # of IService +logger = Logger() + + +logger = Logger() + class SSLContextFactory(ssl.ClientContextFactory): def __init__(self, cert, key): @@ -162,7 +167,7 @@ class OutgoingMail(object): """ dest_addrstr = smtp_sender_result[1][0][0] fromaddr = self._from_address - log.msg('Message sent from %s to %s' % (fromaddr, dest_addrstr)) + logger.info('Message sent from %s to %s' % (fromaddr, dest_addrstr)) emit_async(catalog.SMTP_SEND_MESSAGE_SUCCESS, fromaddr, dest_addrstr) @@ -185,8 +190,7 @@ class OutgoingMail(object): # temporal error. We might want to notify the permanent errors # differently. - err = failure.value - log.err(err) + logger.error(failure) if self._bouncer: self._bouncer.bounce_message( @@ -204,7 +208,7 @@ class OutgoingMail(object): :type encrypt_and_sign_result: tuple """ message, recipient = encrypt_and_sign_result - log.msg("Connecting to SMTP server %s:%s" % (self._host, self._port)) + logger.info("Connecting to SMTP server %s:%s" % (self._host, self._port)) msg = message.as_string(False) # we construct a defer to pass to the ESMTPSenderFactory @@ -297,7 +301,7 @@ class OutgoingMail(object): def if_key_not_found_send_unencrypted(failure, message): failure.trap(KeyNotFound, KeyAddressMismatch) - log.msg('Will send unencrypted message to %s.' % to_address) + logger.info('Will send unencrypted message to %s.' % to_address) emit_async(catalog.SMTP_START_SIGN, self._from_address, to_address) d = self._sign(message, from_address) d.addCallback(signal_sign) @@ -307,8 +311,8 @@ class OutgoingMail(object): emit_async(catalog.SMTP_END_SIGN, self._from_address) return newmsg, recipient - log.msg("Will encrypt the message with %s and sign with %s." - % (to_address, from_address)) + logger.info("Will encrypt the message with %s and sign with %s." + % (to_address, from_address)) emit_async(catalog.SMTP_START_ENCRYPT_AND_SIGN, self._from_address, "%s,%s" % (self._from_address, to_address)) diff --git a/src/leap/bitmask/mail/rfc3156.py b/src/leap/bitmask/mail/rfc3156.py index 7d7bc0f0..1ab631f8 100644 --- a/src/leap/bitmask/mail/rfc3156.py +++ b/src/leap/bitmask/mail/rfc3156.py @@ -22,7 +22,8 @@ Implements RFC 3156: MIME Security with OpenPGP. import base64 from StringIO import StringIO -from twisted.python import log +from twisted.logger import Logger + from email.mime.application import MIMEApplication from email.mime.multipart import MIMEMultipart from email import errors @@ -33,6 +34,7 @@ from email.generator import ( _make_boundary, ) +logger = Logger() # # A generator that solves http://bugs.python.org/issue14983 @@ -163,7 +165,7 @@ def encode_base64(msg): except KeyError: msg['Content-Transfer-Encoding'] = 'base64' elif encoding is not 'base64': - log.err('Unknown content-transfer-encoding: %s' % encoding) + logger.error('Unknown content-transfer-encoding: %s' % encoding) def encode_base64_rec(msg): diff --git a/src/leap/bitmask/mail/smtp/__init__.py b/src/leap/bitmask/mail/smtp/__init__.py index f8b8e65f..90baf668 100644 --- a/src/leap/bitmask/mail/smtp/__init__.py +++ b/src/leap/bitmask/mail/smtp/__init__.py @@ -17,16 +17,16 @@ """ SMTP gateway helper function. """ -import logging import os from twisted.internet import reactor from twisted.internet.error import CannotListenError +from twisted.logger import Logger from leap.common.events import emit_async, catalog from leap.bitmask.mail.smtp.gateway import SMTPFactory -logger = logging.getLogger(__name__) +logger = Logger() SMTP_PORT = 2013 @@ -68,4 +68,4 @@ def run_service(soledad_sessions, keymanager_sessions, sendmail_opts, emit_async(catalog.SMTP_SERVICE_FAILED_TO_START, str(port)) except Exception as exc: logger.error("Unhandled error while launching smtp gateway service") - logger.exception(exc) + logger.error('%r' % exc) diff --git a/src/leap/bitmask/mail/smtp/gateway.py b/src/leap/bitmask/mail/smtp/gateway.py index 16e1af97..b1fafadd 100644 --- a/src/leap/bitmask/mail/smtp/gateway.py +++ b/src/leap/bitmask/mail/smtp/gateway.py @@ -39,7 +39,7 @@ from twisted.cred.portal import Portal, IRealm from twisted.mail import smtp from twisted.mail.imap4 import LOGINCredentials, PLAINCredentials from twisted.internet import defer, protocol -from twisted.python import log +from twisted.logger import Logger from leap.common.check import leap_assert_type from leap.common.events import emit_async, catalog @@ -56,6 +56,8 @@ generator.Generator = RFC3156CompliantGenerator LOCAL_FQDN = "bitmask.local" +logger = Logger() + @implementer(IRealm) class LocalSMTPRealm(object): @@ -296,7 +298,7 @@ class SMTPDelivery(object): # verify if recipient key is available in keyring def found(_): - log.msg("Accepting mail for %s..." % user.dest.addrstr) + logger.debug("Accepting mail for %s..." % user.dest.addrstr) emit_async(catalog.SMTP_RECIPIENT_ACCEPTED_ENCRYPTED, self._userid, user.dest.addrstr) @@ -308,8 +310,9 @@ class SMTPDelivery(object): emit_async(catalog.SMTP_RECIPIENT_REJECTED, self._userid, user.dest.addrstr) raise smtp.SMTPBadRcpt(user.dest.addrstr) - log.msg("Warning: will send an unencrypted message (because " - "encrypted_only' is set to False).") + logger.warn( + 'Warning: will send an unencrypted message (because ' + '"encrypted_only" is set to False).') emit_async( catalog.SMTP_RECIPIENT_ACCEPTED_UNENCRYPTED, self._userid, user.dest.addrstr) @@ -341,8 +344,9 @@ class SMTPDelivery(object): # accept mail from anywhere. To reject an address, raise # smtp.SMTPBadSender here. if str(origin) != str(self._userid): - log.msg("Rejecting sender {0}, expected {1}".format(origin, - self._userid)) + logger.error( + "Rejecting sender {0}, expected {1}".format(origin, + self._userid)) raise smtp.SMTPBadSender(origin) self._origin = origin return origin @@ -392,7 +396,7 @@ class EncryptedMessage(object): :returns: a deferred """ - log.msg("Message data complete.") + logger.debug("Message data complete.") self._lines.append('') # add a trailing newline raw_mail = '\r\n'.join(self._lines) @@ -402,8 +406,8 @@ class EncryptedMessage(object): """ Log an error when the connection is lost. """ - log.msg("Connection lost unexpectedly!") - log.err() + logger.error("Connection lost unexpectedly!") + logger.error() emit_async(catalog.SMTP_CONNECTION_LOST, self._userid, self._user.dest.addrstr) # unexpected loss of connection; don't save diff --git a/src/leap/bitmask/mail/smtp/service.py b/src/leap/bitmask/mail/smtp/service.py index 07c182d6..48e6865b 100644 --- a/src/leap/bitmask/mail/smtp/service.py +++ b/src/leap/bitmask/mail/smtp/service.py @@ -17,16 +17,16 @@ """ SMTP gateway helper function. """ -import logging import os from twisted.internet import reactor from twisted.internet.error import CannotListenError +from twisted.logger import Logger from leap.common.events import emit_async, catalog from leap.bitmask.mail.smtp.gateway import SMTPFactory -logger = logging.getLogger(__name__) +logger = Logger() SMTP_PORT = 2013 @@ -70,4 +70,4 @@ def run_service(soledad_sessions, keymanager_sessions, sendmail_opts, emit_async(catalog.SMTP_SERVICE_FAILED_TO_START, str(port)) except Exception as exc: logger.error("Unhandled error while launching smtp gateway service") - logger.exception(exc) + logger.error('%r' % exc) diff --git a/src/leap/bitmask/mail/sync_hooks.py b/src/leap/bitmask/mail/sync_hooks.py index ff4bf56e..de3a0c1a 100644 --- a/src/leap/bitmask/mail/sync_hooks.py +++ b/src/leap/bitmask/mail/sync_hooks.py @@ -20,19 +20,17 @@ Soledad PostSync Hooks. Process every new document of interest after every soledad synchronization, using the hooks that soledad exposes via plugins. """ -import logging - from re import compile as regex_compile from zope.interface import implements from twisted.internet import defer from twisted.plugin import IPlugin -from twisted.python import log +from twisted.logger import Logger from leap.bitmask.mail import constants from leap.soledad.client.interfaces import ISoledadPostSyncPlugin -logger = logging.getLogger(__name__) +logger = Logger() def _get_doc_type_preffix(s): @@ -58,7 +56,7 @@ class MailProcessingPostSyncHook(object): for doc_id in doc_id_list: if _get_doc_type_preffix(doc_id) in self.watched_doc_types: - log.msg("Mail post-sync hook: processing %s" % doc_id) + logger.info("Mail post-sync hook: processing %s" % doc_id) process_fun(doc_id) return defer.gatherResults(self._processing_deferreds) @@ -79,7 +77,7 @@ class MailProcessingPostSyncHook(object): mbox_uuid = _get_mbox_uuid(mdoc_id) if mbox_uuid: chash = _get_chash_from_mdoc(mdoc_id) - logger.debug("Making index table for %s:%s" % (mbox_uuid, chash)) + logger.debug('making index table for %s:%s' % (mbox_uuid, chash)) index_docid = constants.METAMSGID.format( mbox_uuid=mbox_uuid.replace('-', '_'), chash=chash) @@ -93,7 +91,7 @@ class MailProcessingPostSyncHook(object): def _process_queued_docs(self): assert(self._has_configured_account()) pending = self._pending_docs - log.msg("Mail post-sync hook: processing queued docs") + logger.info("Mail post-sync hook: processing queued docs") def remove_pending_docs(res): self._pending_docs = [] diff --git a/src/leap/bitmask/mail/testing/imap.py b/src/leap/bitmask/mail/testing/imap.py index 75ee9c7f..92bf4d34 100644 --- a/src/leap/bitmask/mail/testing/imap.py +++ b/src/leap/bitmask/mail/testing/imap.py @@ -27,7 +27,7 @@ from twisted.cred.portal import Portal, IRealm from twisted.mail import imap4 from twisted.internet import defer from twisted.protocols import loopback -from twisted.python import log +from twisted.logger import Logger from zope.interface import implementer from leap.bitmask.mail.adaptors import soledad as soledad_adaptor @@ -38,6 +38,8 @@ from leap.bitmask.mail.testing.common import SoledadTestMixin TEST_USER = "testuser@leap.se" TEST_PASSWD = "1234" +logger = Logger() + # # Simple IMAP4 Client for testing @@ -180,7 +182,7 @@ class IMAP4HelperMixin(SoledadTestMixin): self.client.transport.loseConnection() self.server.transport.loseConnection() if hasattr(self, 'function'): - log.err(failure, "Problem with %r" % (self.function,)) + logger.error(failure, "Problem with %r" % (self.function,)) def loopback(self): return loopback.loopbackAsync(self.server, self.client) diff --git a/src/leap/bitmask/util.py b/src/leap/bitmask/util.py index 9120fc40..2cea7d90 100644 --- a/src/leap/bitmask/util.py +++ b/src/leap/bitmask/util.py @@ -21,12 +21,14 @@ import os import platform import sys -from twisted.python import log +from twisted.logger import Logger from leap.common.files import which STANDALONE = getattr(sys, 'frozen', False) +logger = Logger() + def here(module=None): global STANDALONE @@ -68,8 +70,7 @@ def get_gpg_bin_path(): gpgbin = opt break except IndexError as e: - log.msg("Couldn't find the gpg binary!: %s" % (e,)) - log.exception(e) + logger.debug("couldn't find the gpg binary!: %s" % (e,)) if platform.system() == "Darwin": gpgbin = os.path.abspath( os.path.join(here(), "apps", "mail", "gpg")) @@ -87,7 +88,7 @@ def get_gpg_bin_path(): gpgbin = opt break except IndexError as e: - log.msg("Couldn't find the gpg1 binary!: %s" % (e,)) + logger.debug("couldn't find the gpg1 binary!: %s" % (e,)) if gpgbin is None: log.msg("Could not find gpg1 binary") |