summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
authorKali Kaneko (leap communications) <kali@leap.se>2017-04-25 18:00:12 +0200
committerKali Kaneko (leap communications) <kali@leap.se>2017-04-27 19:33:28 +0200
commit9f95446a55533c8cdceec7c4430be5cad752ecb1 (patch)
tree4265c127ee9b2c5f1e038836ad2e7b92ea0cad80 /src
parent9a1548aa01996ce93febe0272f1f8e4dd5e130ff (diff)
[bug] unify logging style using class attr
I changed most of the logger statements to use a class attribute, in this way it's easier to identify which class it's logging them. in some cases I leave a module-level logger, when we're either using functions or when the module it's too small. at the same time I did a general review and cleanup of the logging statements.
Diffstat (limited to 'src')
-rw-r--r--src/leap/bitmask/bonafide/_protocol.py14
-rw-r--r--src/leap/bitmask/bonafide/config.py25
-rw-r--r--src/leap/bitmask/bonafide/service.py7
-rw-r--r--src/leap/bitmask/bonafide/session.py15
-rw-r--r--src/leap/bitmask/core/_session.py6
-rw-r--r--src/leap/bitmask/core/_zmq.py6
-rw-r--r--src/leap/bitmask/core/dispatcher.py10
-rw-r--r--src/leap/bitmask/core/mail_services.py103
-rw-r--r--src/leap/bitmask/core/service.py16
-rw-r--r--src/leap/bitmask/core/web/api.py3
-rw-r--r--src/leap/bitmask/hooks.py8
-rw-r--r--src/leap/bitmask/keymanager/__init__.py28
-rw-r--r--src/leap/bitmask/keymanager/keys.py12
-rw-r--r--src/leap/bitmask/keymanager/nicknym.py26
-rw-r--r--src/leap/bitmask/keymanager/openpgp.py54
-rw-r--r--src/leap/bitmask/keymanager/refresher.py16
-rw-r--r--src/leap/bitmask/keymanager/wrapper.py4
-rw-r--r--src/leap/bitmask/mail/adaptors/soledad.py31
-rw-r--r--src/leap/bitmask/mail/imap/account.py14
-rw-r--r--src/leap/bitmask/mail/imap/mailbox.py64
-rw-r--r--src/leap/bitmask/mail/imap/server.py23
-rw-r--r--src/leap/bitmask/mail/imap/service/__init__.py18
-rw-r--r--src/leap/bitmask/mail/incoming/service.py29
-rw-r--r--src/leap/bitmask/mail/mail.py28
-rw-r--r--src/leap/bitmask/mail/outgoing/service.py19
-rw-r--r--src/leap/bitmask/mail/rfc3156.py4
-rw-r--r--src/leap/bitmask/mail/smtp/__init__.py71
-rw-r--r--src/leap/bitmask/mail/smtp/gateway.py17
-rw-r--r--src/leap/bitmask/mail/smtp/service.py10
-rw-r--r--src/leap/bitmask/mail/sync_hooks.py11
-rw-r--r--src/leap/bitmask/mail/testing/imap.py4
-rw-r--r--src/leap/bitmask/util.py8
-rw-r--r--src/leap/bitmask/vpn/_control.py19
-rw-r--r--src/leap/bitmask/vpn/_management.py71
-rw-r--r--src/leap/bitmask/vpn/launcher.py30
-rw-r--r--src/leap/bitmask/vpn/privilege.py21
-rw-r--r--src/leap/bitmask/vpn/process.py21
37 files changed, 378 insertions, 488 deletions
diff --git a/src/leap/bitmask/bonafide/_protocol.py b/src/leap/bitmask/bonafide/_protocol.py
index 391aa8df..674634d9 100644
--- a/src/leap/bitmask/bonafide/_protocol.py
+++ b/src/leap/bitmask/bonafide/_protocol.py
@@ -38,8 +38,6 @@ from twisted.logger import Logger
# TODO [ ] enable-disable services
# TODO [ ] read provider info
-logger = Logger()
-
COMMANDS = 'signup', 'authenticate', 'logout', 'stats'
_preffix = get_path_prefix()
@@ -53,6 +51,8 @@ class BonafideProtocol(object):
_apis = defaultdict(None)
_sessions = defaultdict(None)
+ log = Logger()
+
def _get_api(self, provider):
# TODO should get deferred
if provider.domain in self._apis:
@@ -85,7 +85,7 @@ class BonafideProtocol(object):
# Service public methods
def do_signup(self, full_id, password, invite=None, autoconf=False):
- logger.debug('SIGNUP for %s' % full_id)
+ self.log.debug('SIGNUP for %s' % full_id)
_, provider_id = config.get_username_and_provider(full_id)
provider = config.Provider(provider_id, autoconf=autoconf)
@@ -132,7 +132,7 @@ class BonafideProtocol(object):
# TODO -- turn this into JSON response
return str(_session.token), str(_session.uuid)
- logger.debug('AUTH for %s' % full_id)
+ self.log.debug('AUTH for %s' % full_id)
# XXX get deferred?
session = self._get_session(provider, full_id, password)
@@ -143,7 +143,7 @@ class BonafideProtocol(object):
def do_logout(self, full_id):
# XXX use the AVATAR here
- logger.debug('LOGOUT for %s' % full_id)
+ self.log.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"))
@@ -162,7 +162,7 @@ class BonafideProtocol(object):
return users
def do_change_password(self, full_id, current_password, new_password):
- logger.debug('change password for %s' % full_id)
+ self.log.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"))
@@ -208,7 +208,7 @@ class BonafideProtocol(object):
pass
def do_stats(self):
- logger.debug('calculating Bonafide Service STATS')
+ self.log.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 1002edbd..b3c35ba1 100644
--- a/src/leap/bitmask/bonafide/config.py
+++ b/src/leap/bitmask/bonafide/config.py
@@ -40,8 +40,6 @@ 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
-logger = Logger()
-
APPNAME = "bonafide"
if platform.system() == 'Windows':
@@ -158,6 +156,7 @@ def delete_provider(domain):
class Provider(object):
+
# TODO add validation
SERVICES_MAP = {
@@ -168,6 +167,8 @@ class Provider(object):
ongoing_bootstrap = defaultdict(None)
stuck_bootstrap = defaultdict(None)
+ log = Logger()
+
def __init__(self, domain, autoconf=False, basedir=None,
check_certificate=True):
# TODO: I need a way to know if it was already configured
@@ -196,7 +197,7 @@ class Provider(object):
if not is_configured:
if autoconf:
- logger.debug(
+ self.log.debug(
'provider %s not configured: downloading files...' %
domain)
self.bootstrap()
@@ -204,7 +205,7 @@ class Provider(object):
raise NotConfiguredError("Provider %s is not configured"
% (domain,))
else:
- logger.debug('provider already initialized')
+ self.log.debug('Provider already initialized')
self.first_bootstrap[self._domain] = defer.succeed(
'already_initialized')
self.ongoing_bootstrap[self._domain] = defer.succeed(
@@ -251,10 +252,10 @@ class Provider(object):
def bootstrap(self):
domain = self._domain
- logger.debug("bootstrapping provider %s" % domain)
+ self.log.debug('Bootstrapping provider %s' % domain)
ongoing = self.ongoing_bootstrap.get(domain)
if ongoing:
- logger.debug('already bootstrapping this provider...')
+ self.log.debug('Already bootstrapping this provider...')
return
self.first_bootstrap[self._domain] = defer.Deferred()
@@ -359,7 +360,7 @@ class Provider(object):
# See: # https://leap.se/code/issues/7906
def further_bootstrap_needs_auth(ignored):
- logger.warn('cannot download services config yet, need auth')
+ self.log.warn('Cannot download services config yet, need auth')
pending_deferred = defer.Deferred()
self.stuck_bootstrap[self._domain] = pending_deferred
return defer.succeed('ok for now')
@@ -382,9 +383,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.
- logger.error(failure)
- logger.debug(
- "COULD NOT VERIFY CONFIGS.JSON, WORKAROUND: DIRECT DOWNLOAD")
+ self.log.debug(
+ 'COULD NOT VERIFY CONFIGS.JSON, WORKAROUND: DIRECT DOWNLOAD')
if 'mx' in self._provider_config.services:
soledad_uri = '/1/config/soledad-service.json'
@@ -412,7 +412,6 @@ class Provider(object):
if stuck:
d = self._get_config_for_all_services(session)
d.addCallback(lambda _: stuck.callback('continue!'))
- d.addErrback(logger.error)
return d
if not self.has_fetched_services_config():
@@ -497,7 +496,7 @@ class Provider(object):
def _load_provider_json(self):
path = self._get_provider_json_path()
if not is_file(path):
- logger.debug("cannot LOAD provider config path %s" % path)
+ self.log.debug('cannot LOAD provider config path %s' % path)
return
with open(path, 'r') as config:
@@ -535,7 +534,7 @@ class Provider(object):
return services_dict
def _fetch_provider_configs_unauthenticated(self, uri, path):
- logger.info('downloading config for %s...' % uri)
+ self.log.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 0f9c6281..b9aaf1af 100644
--- a/src/leap/bitmask/bonafide/service.py
+++ b/src/leap/bitmask/bonafide/service.py
@@ -30,12 +30,13 @@ from twisted.internet import defer
from twisted.logger import Logger
-logger = Logger()
_preffix = get_path_prefix()
class BonafideService(HookableService):
+ log = Logger()
+
def __init__(self, basedir=None):
if not basedir:
basedir = os.path.join(_preffix, 'leap')
@@ -44,7 +45,7 @@ class BonafideService(HookableService):
self.service_hooks = defaultdict(list)
def startService(self):
- logger.debug('starting Bonafide Service')
+ self.log.debug('Starting Bonafide Service')
super(BonafideService, self).startService()
# Commands
@@ -58,7 +59,7 @@ class BonafideService(HookableService):
def notify_bonafide_auth(result):
if not result:
msg = "authentication hook did not return anything"
- logger.debug(msg)
+ self.log.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 732afe53..551bfa2e 100644
--- a/src/leap/bitmask/bonafide/session.py
+++ b/src/leap/bitmask/bonafide/session.py
@@ -24,7 +24,6 @@ from leap.bitmask.bonafide import _srp
from leap.bitmask.bonafide import provider
from leap.bitmask.bonafide._http import httpRequest, cookieAgentFactory
-logger = Logger()
OK = 'ok'
@@ -45,6 +44,8 @@ def _auth_required(func):
class Session(object):
+ log = Logger()
+
def __init__(self, credentials, api, provider_cert):
# TODO check if an anonymous credentials is passed.
# TODO move provider_cert to api object.
@@ -91,7 +92,7 @@ class Session(object):
def authenticate(self):
uri = self._api.get_handshake_uri()
met = self._api.get_handshake_method()
- logger.debug("%s to %s" % (met, uri))
+ self.log.debug('%s to %s' % (met, uri))
params = self._srp_auth.get_handshake_params()
handshake = yield self._request(self._agent, uri, values=params,
@@ -101,7 +102,7 @@ class Session(object):
uri = self._api.get_authenticate_uri(login=self.username)
met = self._api.get_authenticate_method()
- logger.debug("%s to %s" % (met, uri))
+ self.log.debug('%s to %s' % (met, uri))
params = self._srp_auth.get_authentication_params()
auth = yield self._request(self._agent, uri, values=params,
@@ -119,9 +120,7 @@ class Session(object):
def logout(self):
uri = self._api.get_logout_uri()
met = self._api.get_logout_method()
- auth = yield self._request(self._agent, uri, method=met)
- print 'AUTH', auth
- print 'resetting user/pass'
+ yield self._request(self._agent, uri, method=met)
self.username = None
self.password = None
self._initialize_session()
@@ -211,6 +210,8 @@ if __name__ == "__main__":
import sys
from twisted.cred.credentials import UsernamePassword
+ log = Logger()
+
if len(sys.argv) != 4:
print "Usage:", sys.argv[0], "provider", "username", "password"
sys.exit()
@@ -229,7 +230,7 @@ if __name__ == "__main__":
reactor.stop()
def auth_eb(failure):
- logger.error(failure)
+ log.error(failure)
d = session.authenticate()
d.addCallback(print_result)
diff --git a/src/leap/bitmask/core/_session.py b/src/leap/bitmask/core/_session.py
index 9b22f154..ae992f4a 100644
--- a/src/leap/bitmask/core/_session.py
+++ b/src/leap/bitmask/core/_session.py
@@ -27,9 +27,6 @@ from twisted.logger import Logger
from leap.bitmask.hooks import HookableService
-logger = Logger()
-
-
class SessionService(HookableService):
"""
@@ -49,6 +46,7 @@ class SessionService(HookableService):
"""
name = 'sessions'
+ log = Logger()
def __init__(self, basedir, tokens):
service.Service.__init__(self)
@@ -56,7 +54,7 @@ class SessionService(HookableService):
self._tokens = tokens
def startService(self):
- logger.info('starting Session Service')
+ self.log.info('Starting Session Service')
super(SessionService, self).startService()
def stopService(self):
diff --git a/src/leap/bitmask/core/_zmq.py b/src/leap/bitmask/core/_zmq.py
index 30ac743d..af1da9ff 100644
--- a/src/leap/bitmask/core/_zmq.py
+++ b/src/leap/bitmask/core/_zmq.py
@@ -29,7 +29,7 @@ from leap.bitmask.core import ENDPOINT
from leap.bitmask.core.dispatcher import CommandDispatcher
-logger = Logger()
+log = Logger()
class ZMQServerService(service.Service):
@@ -64,8 +64,8 @@ class _DispatcherREPConnection(ZmqREPConnection):
reactor.callLater(0, self.reply, msgId, str(response))
def log_err(self, failure, msgId):
- logger.error(failure)
+ log.failure('Error on dispatcher')
self.defer_reply("ERROR: %r" % failure, msgId)
def do_greet(self):
- logger.info('starting ZMQ dispatcher')
+ log.info('Starting ZMQ dispatcher')
diff --git a/src/leap/bitmask/core/dispatcher.py b/src/leap/bitmask/core/dispatcher.py
index fc17b76a..187ebfd5 100644
--- a/src/leap/bitmask/core/dispatcher.py
+++ b/src/leap/bitmask/core/dispatcher.py
@@ -35,7 +35,7 @@ from leap.common.events import catalog
from .api import APICommand, register_method
-logger = Logger()
+log = Logger()
class DispatchError(Exception):
@@ -546,11 +546,9 @@ def _format_error(failure):
expected = getattr(failure.value, 'expected', False)
if not expected:
- try:
- logger.failure('[DISPATCHER] Unexpected error:')
- except:
- logger.debug('[DISPATCHER] Unexpected error: %r' % failure.value)
- logger.warn(failure.getTraceback())
+ log.error('[DISPATCHER] Unexpected error!')
+ log.error('{0!r}'.format(failure.value))
+ log.error(failure.getTraceback())
# if needed, we could add here the exception type as an extra field
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 70e7b490..eefbbc5c 100644
--- a/src/leap/bitmask/core/mail_services.py
+++ b/src/leap/bitmask/core/mail_services.py
@@ -54,9 +54,6 @@ 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):
@@ -152,12 +149,14 @@ def is_service_ready(service, provider):
class SoledadService(HookableService):
+ log = Logger()
+
def __init__(self, basedir):
service.Service.__init__(self)
self._basedir = basedir
def startService(self):
- logger.info('starting Soledad Service')
+ self.log.info('Starting Soledad Service')
self._container = SoledadContainer(service=self)
super(SoledadService, self).startService()
@@ -174,12 +173,12 @@ class SoledadService(HookableService):
password = kw.get('password')
uuid = kw.get('uuid')
container = self._container
- logger.debug("on_passphrase_entry: "
- "New Soledad Instance: %s" % userid)
+ self.log.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:
- logger.debug('service MX is not ready...')
+ self.log.debug('Service MX is not ready...')
def hook_on_bonafide_auth(self, **kw):
userid = kw['username']
@@ -195,10 +194,10 @@ class SoledadService(HookableService):
container = self._container
if container.get_instance(userid):
- logger.debug("passing a new SRP Token to Soledad: %s" % userid)
+ self.log.debug('Passing a new SRP Token to Soledad: %s' % userid)
container.set_remote_auth_token(userid, token)
else:
- logger.debug("adding a new Soledad Instance: %s" % userid)
+ self.log.debug('Adding a new Soledad Instance: %s' % userid)
container.add_instance(
userid, password, uuid=uuid, token=token)
@@ -210,19 +209,21 @@ class SoledadService(HookableService):
password = kw['password']
soledad = self._container.get_instance(userid)
if soledad is not None:
- logger.info("Change soledad passphrase for %s" % userid)
+ self.log.info('Change soledad passphrase for %s' % userid)
soledad.change_passphrase(unicode(password))
class KeymanagerContainer(Container):
+ log = Logger()
+
def __init__(self, service=None, basedir=DEFAULT_BASEDIR):
self._basedir = os.path.expanduser(basedir)
self._status = {}
super(KeymanagerContainer, self).__init__(service=service)
def add_instance(self, userid, token, uuid, soledad):
- logger.debug("adding Keymanager instance for: %s" % userid)
+ self.log.debug('Adding Keymanager instance for: %s' % userid)
self._set_status(userid, "starting")
keymanager = self._create_keymanager_instance(
userid, token, uuid, soledad)
@@ -252,15 +253,15 @@ class KeymanagerContainer(Container):
def _get_or_generate_keys(self, keymanager, userid):
def _get_key(_):
- logger.info("looking up private key for %s" % userid)
+ self.log.info('Looking up private key for %s' % userid)
return keymanager.get_key(userid, private=True, fetch_remote=False)
def _found_key(key):
- logger.info("found key: %r" % key)
+ self.log.info('Found key: %r' % key)
def _if_not_found_generate(failure):
failure.trap(KeyNotFound)
- logger.info("key not found, generating key for %s" % (userid,))
+ self.log.info('Key not found, generating key for %s' % (userid,))
self._set_status(userid, "starting", keys="generating")
d = keymanager.gen_key()
d.addCallbacks(_send_key, _log_key_error("generating"))
@@ -272,25 +273,25 @@ class KeymanagerContainer(Container):
# but this hasn't been successfully uploaded. How do we know that?
# XXX Should this be a method of bonafide instead?
# -----------------------------------------------------------------
- logger.info("key generated for %s" % userid)
+ self.log.info('Key generated for %s' % userid)
if not keymanager.token:
- logger.debug(
- "token not available, scheduling "
- "a new key sending attempt...")
+ self.log.debug(
+ 'Token not available, scheduling '
+ 'a new key sending attempt...')
return task.deferLater(reactor, 5, _send_key, None)
- logger.info("sending public key to server")
+ self.log.info('Sending public key to server')
d = keymanager.send_key()
d.addCallbacks(
- lambda _: logger.info("key sent to server"),
+ lambda _: self.log.info('Key sent to server'),
_log_key_error("sending"))
return d
def _log_key_error(step):
def log_error(failure):
- logger.error("Error while %s key!" % step)
- logger.error(failure)
+ self.log.error('Error while %s key!' % step)
+ self.log.failure('error!')
error = "Error generating key: %s" % failure.getErrorMessage()
self._set_status(userid, "failure", error=error)
return failure
@@ -298,22 +299,22 @@ class KeymanagerContainer(Container):
def _sync_if_never_synced(ever_synced):
if ever_synced:
- logger.debug("soledad has synced in the past")
+ self.log.debug('Soledad has synced in the past')
return defer.succeed(None)
- logger.debug("soledad has never synced")
+ self.log.debug('Soledad has never synced')
if not keymanager.token:
- logger.debug("no token to sync now, scheduling a new check")
+ self.log.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
- logger.debug("syncing soledad for the first time...")
+ self.log.debug('Syncing soledad for the first time...')
self._set_status(userid, "starting", keys="sync")
return keymanager._soledad.sync()
- logger.debug("checking if soledad has ever synced...")
+ self.log.debug('Checking if soledad has ever synced...')
d = keymanager.ever_synced()
d.addCallback(_sync_if_never_synced)
d.addCallback(_get_key)
@@ -355,13 +356,15 @@ class KeymanagerContainer(Container):
class KeymanagerService(HookableService):
+ log = Logger()
+
def __init__(self, basedir=DEFAULT_BASEDIR):
service.Service.__init__(self)
self._basedir = basedir
self._container = None
def startService(self):
- logger.debug('starting Keymanager Service')
+ self.log.debug('Starting Keymanager Service')
self._container = KeymanagerContainer(self._basedir)
self._container.service = self
self.tokens = {}
@@ -376,7 +379,7 @@ class KeymanagerService(HookableService):
uuid = kw['uuid']
soledad = kw['soledad']
if not container.get_instance(user):
- logger.debug('Adding a new Keymanager instance for %s' % user)
+ self.log.debug('Adding a new Keymanager instance for %s' % user)
if not token:
token = self.tokens.get(user)
container.add_instance(user, token, uuid, soledad)
@@ -393,12 +396,12 @@ class KeymanagerService(HookableService):
container = self._container
if container.get_instance(userid):
- logger.debug(
- 'passing a new SRP Token '
+ self.log.debug(
+ 'Passing a new SRP Token '
'to Keymanager: %s' % userid)
container.set_remote_auth_token(userid, token)
else:
- logger.debug('storing the keymanager token... %s ' % token)
+ self.log.debug('Storing the keymanager token... %s ' % token)
self.tokens[userid] = token
# commands
@@ -464,6 +467,7 @@ class StandardMailService(service.MultiService, HookableService):
"""
name = 'mail'
+ log = Logger()
# TODO factor out Mail Service to inside mail package.
@@ -487,11 +491,11 @@ class StandardMailService(service.MultiService, HookableService):
self.addService(IncomingMailService(self))
def startService(self):
- logger.info('starting mail service')
+ self.log.info('Starting Mail Service')
super(StandardMailService, self).startService()
def stopService(self):
- logger.info('stopping mail service')
+ self.log.info('Stopping Mail service')
super(StandardMailService, self).stopService()
def startInstance(self, userid, soledad, keymanager):
@@ -541,14 +545,14 @@ class StandardMailService(service.MultiService, HookableService):
"""
try to turn on incoming mail service for the user that just logged in
"""
- logger.debug(
- 'looking for incoming mail service for auth: %s' % userid)
+ self.log.debug(
+ 'Looking for incoming mail service for auth: %s' % userid)
multiservice = self.getServiceNamed('incoming_mail')
try:
incoming = multiservice.getServiceNamed(userid)
incoming.startService()
except KeyError:
- logger.debug('no incoming service for %s' % userid)
+ self.log.debug('No incoming service for %s' % userid)
@defer.inlineCallbacks
def _maybe_fetch_smtp_certificate(self, userid):
@@ -579,7 +583,7 @@ class StandardMailService(service.MultiService, HookableService):
except KeyError:
incoming = None
if incoming:
- logger.debug(
+ self.log.debug(
'looking for incoming mail service '
'for logout: %s' % username)
incoming.stopService()
@@ -624,8 +628,8 @@ class StandardMailService(service.MultiService, HookableService):
try:
shutil.rmtree(tokens_folder)
except OSError as e:
- logger.warn("Can't remove tokens folder %s: %s"
- % (tokens_folder, e))
+ self.log.warn("Can't remove tokens folder %s: %s"
+ % (tokens_folder, e))
return
os.mkdir(tokens_folder, 0700)
@@ -646,6 +650,7 @@ class StandardMailService(service.MultiService, HookableService):
class IMAPService(service.Service):
name = 'imap'
+ log = Logger()
def __init__(self, soledad_sessions):
self._soledad_sessions = soledad_sessions
@@ -654,7 +659,7 @@ class IMAPService(service.Service):
super(IMAPService, self).__init__()
def startService(self):
- logger.info('starting imap service')
+ self.log.info('Starting IMAP Service')
port, factory = imap_service.run_service(
self._soledad_sessions, factory=self._factory)
self._port = port
@@ -662,7 +667,7 @@ class IMAPService(service.Service):
super(IMAPService, self).startService()
def stopService(self):
- logger.info("stopping imap service")
+ self.log.info('Stopping IMAP Service')
if self._port:
self._port.stopListening()
self._port = None
@@ -680,6 +685,7 @@ class IMAPService(service.Service):
class SMTPService(service.Service):
name = 'smtp'
+ log = Logger()
def __init__(self, soledad_sessions, keymanager_sessions, sendmail_opts,
basedir=DEFAULT_BASEDIR):
@@ -693,7 +699,7 @@ class SMTPService(service.Service):
super(SMTPService, self).__init__()
def startService(self):
- logger.info('starting smtp service')
+ self.log.info('starting smtp service')
port, factory = smtp_service.run_service(
self._soledad_sessions,
self._keymanager_sessions,
@@ -704,7 +710,7 @@ class SMTPService(service.Service):
super(SMTPService, self).startService()
def stopService(self):
- logger.info('stopping smtp service')
+ self.log.info('Stopping SMTP Service')
if self._port:
self._port.stopListening()
self._port = None
@@ -725,6 +731,7 @@ class IncomingMailService(service.MultiService):
"""
name = 'incoming_mail'
+ log = Logger()
def __init__(self, mail_service):
super(IncomingMailService, self).__init__()
@@ -732,7 +739,7 @@ class IncomingMailService(service.MultiService):
self._status = {}
def startService(self):
- logger.info('starting incoming mail service')
+ self.log.info('Starting Incoming Mail Service')
super(IncomingMailService, self).startService()
def stopService(self):
@@ -745,7 +752,7 @@ class IncomingMailService(service.MultiService):
soledad = self._mail.get_soledad_session(userid)
keymanager = self._mail.get_keymanager_session(userid)
- logger.info('setting up incoming mail service for %s' % userid)
+ self.log.info('Setting up Incoming Mail Service for %s' % userid)
self._start_incoming_mail_instance(
keymanager, soledad, userid)
@@ -773,7 +780,7 @@ class IncomingMailService(service.MultiService):
keymanager, soledad,
inbox, userid,
check_period=INCOMING_CHECK_PERIOD)
- logger.debug('setting incoming mail service for %s' % userid)
+ self.log.debug('Setting Incoming Mail Service for %s' % userid)
incoming_mail.setName(userid)
self.addService(incoming_mail)
@@ -791,7 +798,7 @@ class IncomingMailService(service.MultiService):
def _errback(self, failure, userid):
self._set_status(userid, "failure", error=str(failure))
- logger.error(str(failure))
+ self.log.failure('failure!')
# --------------------------------------------------------------------
#
diff --git a/src/leap/bitmask/core/service.py b/src/leap/bitmask/core/service.py
index c06a5343..2972a51c 100644
--- a/src/leap/bitmask/core/service.py
+++ b/src/leap/bitmask/core/service.py
@@ -37,9 +37,6 @@ from leap.bitmask.core.web.service import HTTPDispatcherService
from leap.bitmask.vpn.service import VPNService
from leap.common.events import server as event_server
-logger = Logger()
-
-
backend = flags.BACKEND
if backend == 'default':
@@ -52,6 +49,9 @@ else:
raise RuntimeError('Backend not supported')
+log = Logger()
+
+
class BitmaskBackend(configurable.ConfigurableService):
"""
@@ -68,7 +68,8 @@ class BitmaskBackend(configurable.ConfigurableService):
# The global token is used for authenticating some of the channels that
# expose the dispatcher. For the moment being, this is the REST API.
self.global_tokens = [uuid.uuid4().hex]
- logger.info('Global token: {0}'.format(self.global_tokens[0]))
+ log.debug(
+ 'Global token: {0}'.format(self.global_tokens[0]))
self._touch_token_file()
# These tokens are user-session tokens. Implemented and rolled back,
@@ -129,13 +130,13 @@ class BitmaskBackend(configurable.ConfigurableService):
sessions.setServiceParent(self)
def _start_child_service(self, name):
- logger.debug('starting backend child service: %s' % name)
+ log.debug('Starting backend child service: %s' % name)
service = self.getServiceNamed(name)
if service:
service.startService()
def _stop_child_service(self, name):
- logger.debug('stopping backend child service: %s' % name)
+ log.debug('Stopping backend child service: %s' % name)
service = self.getServiceNamed(name)
if service:
service.stopService()
@@ -203,7 +204,6 @@ class BitmaskBackend(configurable.ConfigurableService):
try:
service = self.getServiceNamed(label)
except KeyError:
- logger.debug("initializing service: %s" % label)
service = klass(*args, **kw)
service.setName(label)
service.setServiceParent(self)
@@ -282,8 +282,6 @@ class BackendCommands(object):
return {'version_core': __version__}
def do_stats(self):
- print "DO 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/core/web/api.py b/src/leap/bitmask/core/web/api.py
index 01c65bae..7f871711 100644
--- a/src/leap/bitmask/core/web/api.py
+++ b/src/leap/bitmask/core/web/api.py
@@ -40,7 +40,8 @@ class Api(Resource):
d = self.dispatcher.dispatch(command)
d.addCallback(self._write_response, request)
- d.addErrback(log.error)
+ d.addErrback(
+ lambda f: log.error('Error on POST: {0!r}'.format(f)))
return NOT_DONE_YET
def _write_response(self, response, request):
diff --git a/src/leap/bitmask/hooks.py b/src/leap/bitmask/hooks.py
index fb9771e9..3e9324e0 100644
--- a/src/leap/bitmask/hooks.py
+++ b/src/leap/bitmask/hooks.py
@@ -25,7 +25,7 @@ from twisted.logger import Logger
from zope.interface import implementer
-logger = Logger()
+log = Logger()
@implementer(IService)
@@ -47,7 +47,7 @@ class HookableService(Service):
def register_hook(self, name, listener):
if not hasattr(self, 'event_listeners'):
self.event_listeners = defaultdict(list)
- logger.debug('registering hook %s->%s' % (name, listener))
+ log.debug('registering hook %s->%s' % (name, listener))
self.event_listeners[name].append(listener)
def trigger_hook(self, name, **data):
@@ -55,8 +55,8 @@ class HookableService(Service):
def react_to_hook(listener, name, **kw):
try:
getattr(listener, 'hook_' + name)(**kw)
- except AttributeError as exc:
- logger.failure('Error while triggering hook')
+ except AttributeError:
+ log.failure('Error while triggering hook')
raise RuntimeError(
"Tried to notify a hook, but the listener "
"service class %s does not seem to have "
diff --git a/src/leap/bitmask/keymanager/__init__.py b/src/leap/bitmask/keymanager/__init__.py
index fb4668c7..190e26ff 100644
--- a/src/leap/bitmask/keymanager/__init__.py
+++ b/src/leap/bitmask/keymanager/__init__.py
@@ -40,12 +40,6 @@ from leap.bitmask.keymanager.refresher import RandomRefreshPublicKey
from leap.bitmask.keymanager.validation import ValidationLevels, can_upgrade
from leap.bitmask.keymanager.openpgp import OpenPGPScheme
-logger = Logger()
-
-
-#
-# The Key Manager
-#
class KeyManager(object):
@@ -53,6 +47,8 @@ class KeyManager(object):
# server's key storage constants
#
+ log = Logger()
+
OPENPGP_KEY = 'openpgp'
PUBKEY_KEY = "user[public_key]"
@@ -94,7 +90,7 @@ class KeyManager(object):
try:
self._combined_ca_bundle = combined_ca_bundle or create()
except Exception:
- logger.warn('error while creating combined ca bundle')
+ self.log.warn('Error while creating combined ca bundle')
self._combined_ca_bundle = ''
self._async_client = HTTPClient(self._combined_ca_bundle)
@@ -155,17 +151,17 @@ class KeyManager(object):
except keymanager_errors.KeyNotFound:
raise
except IOError as e:
- logger.warn("HTTP error retrieving key: %r" % (e,))
- logger.warn("%s" % (content,))
+ self.log.warn("HTTP error retrieving key: %r" % (e,))
+ self.log.warn("%s" % (content,))
raise keymanager_errors.KeyNotFound(e.message), \
None, sys.exc_info()[2]
except ValueError as v:
- logger.warn("invalid JSON data from key: %s" % (uri,))
+ self.log.warn("Invalid JSON data from key: %s" % (uri,))
raise keymanager_errors.KeyNotFound(v.message + ' - ' + uri), \
None, sys.exc_info()[2]
except Exception as e:
- logger.warn("error retrieving key: %r" % (e,))
+ self.log.warn("Error retrieving key: %r" % (e,))
raise keymanager_errors.KeyNotFound(e.message), \
None, sys.exc_info()[2]
# Responses are now text/plain, although it's json anyway, but
@@ -190,7 +186,7 @@ class KeyManager(object):
def check_404(response):
if response.code == NOT_FOUND:
message = '%s: %s key not found.' % (response.code, address)
- logger.warn(message)
+ self.log.warn(message)
raise KeyNotFound(message), None, sys.exc_info()[2]
return response
@@ -218,7 +214,7 @@ class KeyManager(object):
try:
content = yield self._async_client.request(str(uri), 'GET')
except Exception as e:
- logger.warn("There was a problem fetching key: %s" % (e,))
+ self.log.warn("There was a problem fetching key: %s" % (e,))
raise keymanager_errors.KeyNotFound(uri)
if not content:
raise keymanager_errors.KeyNotFound(uri)
@@ -307,8 +303,7 @@ class KeyManager(object):
:raise UnsupportedKeyTypeError: if invalid key type
"""
- logger.debug("getting key for %s" % (address,))
-
+ self.log.debug('Getting key for %s' % (address,))
emit_async(catalog.KEYMANAGER_LOOKING_FOR_KEY, address)
def key_found(key):
@@ -455,7 +450,6 @@ class KeyManager(object):
:raise UnsupportedKeyTypeError: if invalid key type
"""
-
@defer.inlineCallbacks
def encrypt(keys):
pubkey, signkey = keys
@@ -726,7 +720,7 @@ class KeyManager(object):
:raise UnsupportedKeyTypeError: if invalid key type
"""
- logger.info("fetch key for %s from %s" % (address, uri))
+ self.log.info('Fetch key for %s from %s' % (address, uri))
key_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 622c1c68..54609c05 100644
--- a/src/leap/bitmask/keymanager/keys.py
+++ b/src/leap/bitmask/keymanager/keys.py
@@ -30,7 +30,7 @@ from leap.bitmask.keymanager.wrapper import TempGPGWrapper
from leap.bitmask.keymanager.validation import ValidationLevels
from leap.bitmask.keymanager import documents as doc
-logger = Logger()
+log = Logger()
#
@@ -71,9 +71,9 @@ def build_key_from_dict(key, active=None):
try:
validation = ValidationLevels.get(active[doc.KEY_VALIDATION_KEY])
except ValueError:
- logger.error("Not valid validation level (%s) for key %s",
- (active[doc.KEY_VALIDATION_KEY],
- active[doc.KEY_FINGERPRINT_KEY]))
+ log.error('Not valid validation level (%s) for key %s',
+ (active[doc.KEY_VALIDATION_KEY],
+ active[doc.KEY_FINGERPRINT_KEY]))
last_audited_at = _to_datetime(active[doc.KEY_LAST_AUDITED_AT_KEY])
encr_used = active[doc.KEY_ENCR_USED_KEY]
sign_used = active[doc.KEY_SIGN_USED_KEY]
@@ -112,6 +112,7 @@ def _to_unix_time(date):
class OpenPGPKey(object):
+
"""
Base class for OpenPGP keys.
"""
@@ -120,6 +121,7 @@ class OpenPGPKey(object):
'private', 'length', 'expiry_date', 'validation',
'last_audited_at', 'refreshed_at',
'encr_used', 'sign_used', '_index', '_gpgbinary')
+ log = Logger()
def __init__(self, address=None, gpgbinary=None, uids=[], fingerprint="",
key_data="", private=False, length=0, expiry_date=None,
@@ -184,7 +186,7 @@ class OpenPGPKey(object):
def merge(self, newkey):
if newkey.fingerprint != self.fingerprint:
- logger.critical(
+ self.log.critical(
"Can't put a key whith the same key_id and different "
"fingerprint: %s, %s"
% (newkey.fingerprint, self.fingerprint))
diff --git a/src/leap/bitmask/keymanager/nicknym.py b/src/leap/bitmask/keymanager/nicknym.py
index 7c738da0..8e3a08f9 100644
--- a/src/leap/bitmask/keymanager/nicknym.py
+++ b/src/leap/bitmask/keymanager/nicknym.py
@@ -1,6 +1,6 @@
# -*- coding: utf-8 -*-
# nicknym.py
-# Copyright (C) 2016 LEAP
+# Copyright (C) 2016-2017 LEAP
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@@ -17,10 +17,10 @@
import json
import sys
-import logging
import urllib
from twisted.internet import defer
+from twisted.logger import Logger
from twisted.web import client
from twisted.web._responses import NOT_FOUND
@@ -30,14 +30,14 @@ from leap.common.http import HTTPClient
from leap.common.decorators import memoized_method
-logger = logging.getLogger(__name__)
-
-
class Nicknym(object):
+
"""
Responsible for communication to the nicknym server.
"""
+ log = Logger()
+
PUBKEY_KEY = "user[public_key]"
def __init__(self, nickserver_uri, ca_cert_path, token):
@@ -83,12 +83,12 @@ class Nicknym(object):
body=str(data),
headers=headers)
except Exception as e:
- logger.warning("Error uploading key: %r" % (e,))
+ self.log.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,))
+ self.log.warn('Error uploading key: %r' % (res,))
raise Exception(res)
@defer.inlineCallbacks
@@ -105,19 +105,17 @@ class Nicknym(object):
try:
content = yield self._fetch_and_handle_404_from_nicknym(uri)
json_content = json.loads(content)
-
except KeyNotFound:
raise
except IOError as e:
- logger.warning("HTTP error retrieving key: %r" % (e,))
- logger.warning("%s" % (content,))
+ self.log.warn('HTTP error retrieving key: %r' % (e,))
+ self.log.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,))
+ self.log.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,))
+ self.log.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
@@ -141,7 +139,7 @@ class Nicknym(object):
if response.code == NOT_FOUND:
message = ' %s: Key not found. Request: %s' \
% (response.code, uri)
- logger.warning(message)
+ self.log.warn(message)
raise KeyNotFound(message), None, sys.exc_info()[2]
return response
diff --git a/src/leap/bitmask/keymanager/openpgp.py b/src/leap/bitmask/keymanager/openpgp.py
index b72c62ce..8c9dc1e8 100644
--- a/src/leap/bitmask/keymanager/openpgp.py
+++ b/src/leap/bitmask/keymanager/openpgp.py
@@ -1,6 +1,6 @@
# -*- coding: utf-8 -*-
# openpgp.py
-# Copyright (C) 2013-2016 LEAP
+# Copyright (C) 2013-2017 LEAP
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@@ -14,9 +14,11 @@
#
# You should have received a copy of the GNU General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
+
"""
Infrastructure for using OpenPGP keys in Key Manager.
"""
+
import os
import re
import tempfile
@@ -74,13 +76,6 @@ except ImportError:
return bool(result.key)
-logger = Logger()
-
-
-#
-# A temporary GPG keyring wrapped to provide OpenPGP functionality.
-#
-
# This function will be used to call blocking GPG functions outside
# of Twisted reactor and match the concurrent calls to the amount of CPU cores
cpu_core_semaphore = defer.DeferredSemaphore(cpu_count())
@@ -91,16 +86,22 @@ def from_thread(func, *args, **kwargs):
return cpu_core_semaphore.run(call)
+log = Logger()
+
+
#
# The OpenPGP wrapper
#
class OpenPGPScheme(object):
+
"""
A wrapper for OpenPGP keys management and use (encryption, decyption,
signing and verification).
"""
+ log = Logger()
+
# type used on the soledad documents
KEY_TYPE = OpenPGPKey.__name__
ACTIVE_TYPE = KEY_TYPE + KEYMANAGER_ACTIVE_TYPE
@@ -186,11 +187,11 @@ class OpenPGPScheme(object):
name_real=address,
name_email=address,
name_comment='')
- logger.info("About to generate keys... "
- "This might take SOME time.")
+ self.log.info('About to generate keys... '
+ 'This might take SOME time.')
yield from_thread(gpg.gen_key, params)
- logger.info("Keys for %s have been successfully "
- "generated." % (address,))
+ self.log.info('Keys for %s have been successfully '
+ 'generated.' % (address,))
pubkeys = gpg.list_keys()
# assert for new key characteristics
@@ -509,8 +510,8 @@ class OpenPGPScheme(object):
if len(docs) == 0:
raise errors.KeyNotFound(key)
elif len(docs) > 1:
- logger.warn("There is more than one key for fingerprint %s"
- % key.fingerprint)
+ self.log.warn('There is more than one key for fingerprint %s'
+ % key.fingerprint)
has_deleted = False
deferreds = []
@@ -559,7 +560,7 @@ class OpenPGPScheme(object):
"""
stderr = getattr(result, 'stderr', None)
if stderr:
- logger.debug("%s" % (stderr,))
+ log.debug("%s" % (stderr,))
if getattr(result, 'ok', None) is not True:
raise errors.GPGError(
'Failed to encrypt/decrypt: %s' % stderr)
@@ -612,7 +613,7 @@ class OpenPGPScheme(object):
self._assert_gpg_result_ok(result)
defer.returnValue(result.data)
except errors.GPGError as e:
- logger.warn('Failed to encrypt: %s.' % str(e))
+ self.log.warn('Failed to encrypt: %s.' % str(e))
raise errors.EncryptError()
@defer.inlineCallbacks
@@ -658,7 +659,7 @@ class OpenPGPScheme(object):
defer.returnValue((result.data, sign_valid))
except errors.GPGError as e:
- logger.warn('Failed to decrypt: %s.' % str(e))
+ self.log.warn('Failed to decrypt: %s.' % str(e))
raise errors.DecryptError(str(e))
def is_encrypted(self, data):
@@ -803,8 +804,8 @@ class OpenPGPScheme(object):
:rtype: Deferred
"""
def log_key_doc(doc):
- logger.error("\t%s: %s" % (doc.content[KEY_UIDS_KEY],
- doc.content[KEY_FINGERPRINT_KEY]))
+ self.log.error("\t%s: %s" % (doc.content[KEY_UIDS_KEY],
+ doc.content[KEY_FINGERPRINT_KEY]))
def cmp_key(d1, d2):
return cmp(d1.content[KEY_REFRESHED_AT_KEY],
@@ -833,8 +834,8 @@ class OpenPGPScheme(object):
pass
def log_active_doc(doc):
- logger.error("\t%s: %s" % (doc.content[KEY_ADDRESS_KEY],
- doc.content[KEY_FINGERPRINT_KEY]))
+ self.log.error("\t%s: %s" % (doc.content[KEY_ADDRESS_KEY],
+ doc.content[KEY_FINGERPRINT_KEY]))
def cmp_active(d1, d2):
# XXX: for private keys it will be nice to check which key is known
@@ -857,9 +858,9 @@ class OpenPGPScheme(object):
defer.returnValue(doc)
def _repair_docs(self, doclist, cmp_func, log_func):
- logger.error("BUG ---------------------------------------------------")
- logger.error("There is more than one doc of type %s:"
- % (doclist[0].content[KEY_TYPE_KEY],))
+ self.log.error("BUG -------------------------------------------------")
+ self.log.error("There is more than one doc of type %s:"
+ % (doclist[0].content[KEY_TYPE_KEY],))
doclist.sort(cmp=cmp_func, reverse=True)
log_func(doclist[0])
@@ -869,9 +870,8 @@ class OpenPGPScheme(object):
d = self._soledad.delete_doc(doc)
deferreds.append(d)
- logger.error("")
- logger.error(traceback.extract_stack())
- logger.error("BUG (please report above info) ------------------------")
+ self.log.error('Error repairing')
+ self.log.error("BUG (please report above info) ----------------------")
d = defer.gatherResults(deferreds, consumeErrors=True)
d.addCallback(lambda _: doclist[0])
return d
diff --git a/src/leap/bitmask/keymanager/refresher.py b/src/leap/bitmask/keymanager/refresher.py
index 694a537f..d1ae9f84 100644
--- a/src/leap/bitmask/keymanager/refresher.py
+++ b/src/leap/bitmask/keymanager/refresher.py
@@ -28,18 +28,18 @@ from random import choice, randrange
DEBUG_STOP_REFRESH = "Stop to refresh the key directory ..."
DEBUG_START_REFRESH = "Start to refresh the key directory ..."
-ERROR_UNEQUAL_FINGERPRINTS = "[WARNING] Your provider might be cheat " \
- "on you, and gave a wrong key back. " \
- "Fingerprints are unequal, old %s new %s "
+ERROR_UNEQUAL_FINGERPRINTS = "[WARNING] Your provider *might* be cheating " \
+ "on you, and given a wrong key back. " \
+ "Fingerprints do not match: old-> %s, new-> %s "
MIN_RANDOM_INTERVAL_RANGE = 4 * 60 # four minutes
MAX_RANDOM_INTERVAL_RANGE = 6 * 60 # six minutes
-logger = Logger()
-
class RandomRefreshPublicKey(object):
+ log = Logger()
+
def __init__(self, openpgp, keymanager):
"""
Initialize the RandomRefreshPublicKey.
@@ -59,14 +59,14 @@ class RandomRefreshPublicKey(object):
:rtype: A deferred.
"""
self._loop.start(self._get_random_interval_to_refresh(), False)
- logger.debug(DEBUG_START_REFRESH)
+ self.log.debug(DEBUG_START_REFRESH)
def stop(self):
"""
Stop the looping call with random interval.
"""
self._loop.stop()
- logger.debug(DEBUG_STOP_REFRESH)
+ self.log.debug(DEBUG_STOP_REFRESH)
@defer.inlineCallbacks
def _get_random_key(self):
@@ -110,7 +110,7 @@ class RandomRefreshPublicKey(object):
fetch_key_with_fingerprint(old_key.fingerprint)
if old_updated_key.fingerprint != old_key.fingerprint:
- logger.error(ERROR_UNEQUAL_FINGERPRINTS %
+ self.log.error(ERROR_UNEQUAL_FINGERPRINTS %
(old_key.fingerprint, old_updated_key.fingerprint))
defer.returnValue(None)
diff --git a/src/leap/bitmask/keymanager/wrapper.py b/src/leap/bitmask/keymanager/wrapper.py
index ef8e6640..eb5074f3 100644
--- a/src/leap/bitmask/keymanager/wrapper.py
+++ b/src/leap/bitmask/keymanager/wrapper.py
@@ -35,7 +35,6 @@ except ImportError:
GNUPG_NG = False
-logger = Logger()
class TempGPGWrapper(object):
@@ -43,6 +42,7 @@ class TempGPGWrapper(object):
A context manager that wraps a temporary GPG keyring which only contains
the keys given at object creation.
"""
+ log = Logger()
def __init__(self, keys=None, gpgbinary=None):
"""
@@ -160,6 +160,6 @@ class TempGPGWrapper(object):
homedir = os.path.normpath(homedir).replace("\\", "/")
homedir = str(homedir.replace("c:/", "c://"))
if platform.system() == "Windows":
- logger.error("BUG! Not erasing folder in Windows")
+ self.log.error("BUG! Not erasing folder in Windows")
return
shutil.rmtree(homedir)
diff --git a/src/leap/bitmask/mail/adaptors/soledad.py b/src/leap/bitmask/mail/adaptors/soledad.py
index 6a057d65..a3e011a3 100644
--- a/src/leap/bitmask/mail/adaptors/soledad.py
+++ b/src/leap/bitmask/mail/adaptors/soledad.py
@@ -41,8 +41,6 @@ from leap.soledad.common import l2db
from leap.soledad.common.document import SoledadDocument
-logger = Logger()
-
# TODO
# [ ] Convenience function to create mail specifying subject, date, etc?
@@ -67,6 +65,7 @@ def cleanup_deferred_locks():
class SoledadDocumentWrapper(models.DocumentWrapper):
+
"""
A Wrapper object that can be manipulated, passed around, and serialized in
a format that the Soledad Store understands.
@@ -74,6 +73,9 @@ class SoledadDocumentWrapper(models.DocumentWrapper):
It ensures atomicity of the document operations on creation, update and
deletion.
"""
+
+ log = Logger()
+
# TODO we could also use a _dirty flag (in models)
# TODO add a get_count() method ??? -- that is extended over l2db.
@@ -186,7 +188,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)
+ self.log.debug('Got conflict while putting %s' % doc_id)
def delete(self, store):
"""
@@ -506,7 +508,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 == "":
- logger.warn("Empty raw field in cdoc %s" % doc_id)
+ self.log.warn('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):
@@ -588,7 +590,7 @@ class MessageWrapper(object):
self.d.append(cdoc.create(store))
def log_all_inserted(result):
- logger.debug("All parts inserted for msg!")
+ self.log.debug('All parts inserted for msg!')
return result
self.all_inserted_d = defer.gatherResults(self.d, consumeErrors=True)
@@ -850,6 +852,8 @@ class SoledadMailAdaptor(SoledadIndexMixin):
mboxwrapper_klass = MailboxWrapper
+ log = Logger()
+
def __init__(self):
SoledadIndexMixin.__init__(self)
@@ -948,15 +952,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
- logger.debug("BUG ------------------------------------------")
- logger.debug(
+ self.log.debug("BUG ------------------------------------------")
+ self.log.debug(
"BUG: Error while retrieving part docs for mdoc id %s" %
mdoc_id)
- logger.debug("BUG (please report above info) ---------------")
+ self.log.debug("BUG (please report above info) ---------------")
return []
def _err_log_cannot_find_msg(failure):
- logger.error("BUG: Error while getting msg (uid=%s)" % uid)
+ self.log.error('BUG: Error while getting msg (uid=%s)' % uid)
return None
if get_cdocs:
@@ -1089,7 +1093,7 @@ class SoledadMailAdaptor(SoledadIndexMixin):
unseen_index = indexes.TYPE_MBOX_SEEN_IDX
d = store.get_count_from_index(unseen_index, type_, uuid, "0")
- d.addErrback(self._errback)
+ d.addErrback(lambda f: self.log.error('Error on count_unseen'))
return d
def get_count_recent(self, store, mbox_uuid):
@@ -1106,7 +1110,7 @@ class SoledadMailAdaptor(SoledadIndexMixin):
recent_index = indexes.TYPE_MBOX_RECENT_IDX
d = store.get_count_from_index(recent_index, type_, uuid, "1")
- d.addErrback(self._errback)
+ d.addErrback(lambda f: self.log.error('Error on count_recent'))
return d
# search api
@@ -1124,7 +1128,7 @@ class SoledadMailAdaptor(SoledadIndexMixin):
def get_mdoc_id(hdoc):
if not hdoc:
- logger.warn("Could not find a HDOC with MSGID %s" % msgid)
+ self.log.warn("Could not find a HDOC with MSGID %s" % msgid)
return None
hdoc = hdoc[0]
mdoc_id = hdoc.doc_id.replace("H-", "M-%s-" % uuid)
@@ -1175,9 +1179,6 @@ class SoledadMailAdaptor(SoledadIndexMixin):
"""
return MailboxWrapper.get_all(store)
- def _errback(self, failure):
- logger.failure()
-
def _split_into_parts(raw):
# TODO signal that we can delete the original message!-----
diff --git a/src/leap/bitmask/mail/imap/account.py b/src/leap/bitmask/mail/imap/account.py
index 63d214e4..9b26dbaa 100644
--- a/src/leap/bitmask/mail/imap/account.py
+++ b/src/leap/bitmask/mail/imap/account.py
@@ -32,16 +32,6 @@ from leap.bitmask.mail.mail import Account
from leap.bitmask.mail.imap.mailbox import IMAPMailbox, normalize_mailbox
from leap.soledad.client import Soledad
-logger = Logger()
-
-PROFILE_CMD = os.environ.get('LEAP_PROFILE_IMAPCMD', False)
-
-if PROFILE_CMD:
- def _debugProfiling(result, cmdname, start):
- took = (time.time() - start) * 1000
- logger.debug("CMD " + cmdname + " TOOK: " + str(took) + " msec")
- return result
-
#######################################
# Soledad IMAP Account
@@ -49,6 +39,7 @@ if PROFILE_CMD:
class IMAPAccount(object):
+
"""
An implementation of an imap4 Account
that is backed by Soledad Encrypted Documents.
@@ -57,6 +48,7 @@ class IMAPAccount(object):
implements(imap4.IAccount, imap4.INamespacePresenter)
selected = None
+ log = Logger()
def __init__(self, store, user_id, d=defer.Deferred()):
"""
@@ -246,7 +238,7 @@ class IMAPAccount(object):
def check_it_exists(mailboxes):
if name not in mailboxes:
- logger.warn('SELECT: No such mailbox!')
+ self.log.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 836b38fd..cc5d5df6 100644
--- a/src/leap/bitmask/mail/imap/mailbox.py
+++ b/src/leap/bitmask/mail/imap/mailbox.py
@@ -39,38 +39,11 @@ 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 = Logger()
-
# TODO LIST
-# [ ] Restore profile_cmd instrumentation
# [ ] finish the implementation of IMailboxListener
# [ ] implement the rest of ISearchableMailbox
-"""
-If the environment variable `LEAP_SKIPNOTIFY` is set, we avoid
-notifying clients of new messages. Use during stress tests.
-"""
-NOTIFY_NEW = not os.environ.get('LEAP_SKIPNOTIFY', False)
-PROFILE_CMD = os.environ.get('LEAP_PROFILE_IMAPCMD', False)
-
-if PROFILE_CMD:
-
- def _debugProfiling(result, cmdname, start):
- took = (time.time() - start) * 1000
- logger.debug("CMD " + cmdname + " TOOK: " + str(took) + " msec")
- return result
-
- def do_profile_cmd(d, name):
- """
- Add the profiling debug to the passed callback.
- :param d: deferred
- :param name: name of the command
- :type name: str
- """
- d.addCallback(_debugProfiling, name, time.time())
- d.addErrback(lambda f: logger.error(f.getTraceback()))
-
INIT_FLAGS = (MessageFlags.SEEN_FLAG, MessageFlags.ANSWERED_FLAG,
MessageFlags.FLAGGED_FLAG, MessageFlags.DELETED_FLAG,
MessageFlags.DRAFT_FLAG, MessageFlags.RECENT_FLAG,
@@ -107,6 +80,7 @@ def make_collection_listener(mailbox):
class IMAPMailbox(object):
+
"""
A Soledad-backed IMAP mailbox.
@@ -115,6 +89,7 @@ class IMAPMailbox(object):
MessageCollection class. We receive an instance of it and it is made
accessible in the `collection` attribute.
"""
+
implements(
imap4.IMailbox,
imap4.IMailboxInfo,
@@ -133,6 +108,8 @@ class IMAPMailbox(object):
CMD_UIDVALIDITY = "UIDVALIDITY"
CMD_UNSEEN = "UNSEEN"
+ log = Logger()
+
# TODO we should turn this into a datastructure with limited capacity
_listeners = defaultdict(set)
@@ -184,12 +161,10 @@ class IMAPMailbox(object):
:param listener: listener to add
:type listener: an object that implements IMailboxListener
"""
- if not NOTIFY_NEW:
- return
listeners = self.listeners
- logger.debug('adding mailbox listener: %s. Total: %s' % (
- listener, len(listeners)))
+ self.log.debug('Adding mailbox listener: %s. Total: %s' % (
+ listener, len(listeners)))
listeners.add(listener)
def removeListener(self, listener):
@@ -407,7 +382,8 @@ class IMAPMailbox(object):
d = self.collection.add_msg(message, flags, date=date,
notify_just_mdoc=notify_just_mdoc)
- d.addErrback(lambda failure: logger.error(failure))
+ d.addErrback(
+ lambda failure: self.log.failure('Error while adding msg'))
return d
def notify_new(self, *args):
@@ -432,7 +408,7 @@ class IMAPMailbox(object):
d = self._get_notify_count()
d.addCallback(cbNotifyNew)
d.addCallback(self.collection.cb_signal_unread_to_ui)
- d.addErrback(lambda failure: logger.error(failure))
+ d.addErrback(lambda failure: self.log.failure('Error while notify'))
def _get_notify_count(self):
"""
@@ -451,7 +427,7 @@ class IMAPMailbox(object):
def log_num_msg(result):
exists, recent = tuple(result)
- logger.debug("NOTIFY (%r): there are %s messages, %s recent" % (
+ self.log.debug("NOTIFY (%r): there are %s messages, %s recent" % (
self.mbox_name, exists, recent))
return result
@@ -515,7 +491,8 @@ class IMAPMailbox(object):
d = self._bound_seq(messages_asked, uid)
if uid:
d.addCallback(get_range)
- d.addErrback(lambda f: logger.error(f))
+ d.addErrback(
+ lambda f: self.log.failure('Error getting msg range'))
return d
def _bound_seq(self, messages_asked, uid):
@@ -619,12 +596,15 @@ class IMAPMailbox(object):
d = defer.gatherResults(d_msg, consumeErrors=True)
d.addCallback(_get_imap_msg)
d.addCallback(_zip_msgid)
- d.addErrback(lambda failure: logger.error(failure))
+ d.addErrback(
+ lambda failure: self.log.error(
+ 'Error getting msg for range'))
return d
d = self._get_messages_range(messages_asked, uid)
d.addCallback(get_imap_messages_for_range)
- d.addErrback(lambda failure: logger.error(failure))
+ d.addErrback(
+ lambda failure: self.log.failure('Error on fetch'))
return d
def fetch_flags(self, messages_asked, uid):
@@ -802,17 +782,15 @@ class IMAPMailbox(object):
read-write.
"""
if not self.isWriteable():
- logger.info('read only mailbox!')
+ self.log.info('Read only mailbox!')
raise imap4.ReadOnlyMailbox
d = defer.Deferred()
reactor.callLater(0, self._do_store, messages_asked, flags,
mode, uid, d)
- if PROFILE_CMD:
- do_profile_cmd(d, "STORE")
d.addCallback(self.collection.cb_signal_unread_to_ui)
- d.addErrback(lambda f: logger.error(f))
+ d.addErrback(lambda f: self.log.error('Error on store'))
return d
def _do_store(self, messages_asked, flags, mode, uid, observer):
@@ -888,14 +866,14 @@ class IMAPMailbox(object):
if len(query) > 2:
if query[1] == 'HEADER' and query[2].lower() == "message-id":
msgid = str(query[3]).strip()
- logger.debug("Searching for %s" % (msgid,))
+ self.log.debug('Searching for %s' % (msgid,))
d = self.collection.get_uid_from_msgid(str(msgid))
d.addCallback(lambda result: [result])
return d
# nothing implemented for any other query
- logger.warn("Cannot process query: %s" % (query,))
+ self.log.warn('Cannot process query: %s' % (query,))
return []
# IMessageCopier
diff --git a/src/leap/bitmask/mail/imap/server.py b/src/leap/bitmask/mail/imap/server.py
index 897e1f05..9eef6e83 100644
--- a/src/leap/bitmask/mail/imap/server.py
+++ b/src/leap/bitmask/mail/imap/server.py
@@ -32,10 +32,8 @@ 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.
"""
@@ -62,16 +60,21 @@ def _getContentType(msg):
major = minor = None
return major, minor, attrs
+
# Monkey-patch _getContentType to avoid bug that passes lower-case boundary in
# BODYSTRUCTURE response.
+
imap4._getContentType = _getContentType
class LEAPIMAPServer(imap4.IMAP4Server):
+
"""
An IMAP4 Server with a LEAP Storage Backend.
"""
+ log = Logger()
+
#############################################################
#
# Twisted imap4 patch to workaround bad mime rendering in TB.
@@ -167,7 +170,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
msg = line[:7] + " [...]"
else:
msg = copy(line)
- logger.debug('rcv (%s): %s' % (self.state, msg))
+ self.log.debug('rcv (%s): %s' % (self.state, msg))
imap4.IMAP4Server.lineReceived(self, line)
def close_server_connection(self):
@@ -452,7 +455,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
def _subscribeEb(failure):
m = failure.value
- logger.error()
+ self.log.error('Error on SUBSCRIBE')
if failure.check(imap4.MailboxException):
self.sendNegativeResponse(tag, str(m))
else:
@@ -477,7 +480,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
def _unsubscribeEb(failure):
m = failure.value
- logger.error()
+ self.log.error('Error on UNSUBSCRIPBE')
if failure.check(imap4.MailboxException):
self.sendNegativeResponse(tag, str(m))
else:
@@ -512,7 +515,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
elif failure.check(imap4.MailboxException):
self.sendNegativeResponse(tag, str(m))
else:
- logger.error()
+ self.log.error('Error on RENAME')
self.sendBadResponse(
tag,
"Server error encountered while "
@@ -539,7 +542,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
if failure.check(imap4.MailboxException):
self.sendNegativeResponse(tag, str(c))
else:
- logger.error()
+ self.log.error('Error on CREATE')
self.sendBadResponse(
tag, "Server error encountered while creating mailbox")
@@ -564,7 +567,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
if failure.check(imap4.MailboxException):
self.sendNegativeResponse(tag, str(m))
else:
- logger.error()
+ self.log.error('Error on DELETE')
self.sendBadResponse(
tag,
"Server error encountered while deleting mailbox")
@@ -600,7 +603,7 @@ class LEAPIMAPServer(imap4.IMAP4Server):
def _ebAppendGotMailbox(self, failure, tag):
self.sendBadResponse(
tag, "Server error encountered while opening mailbox.")
- logger.error(failure)
+ self.log.failure('Error appending')
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 880ff238..b3673c2e 100644
--- a/src/leap/bitmask/mail/imap/service/__init__.py
+++ b/src/leap/bitmask/mail/imap/service/__init__.py
@@ -37,7 +37,7 @@ from leap.bitmask.mail.imap.server import LEAPIMAPServer
# TODO: leave only an implementor of IService in here
-logger = Logger()
+log = Logger()
DO_MANHOLE = os.environ.get("LEAP_MAIL_MANHOLE", None)
if DO_MANHOLE:
@@ -137,23 +137,15 @@ class LeapIMAPFactory(ServerFactory):
:param addr: remote ip address
:type addr: str
"""
- # TODO should reject anything from addr != localhost,
- # just in case.
- logger.debug("Building protocol for connection %s" % addr)
imapProtocol = self.protocol(self._soledad_sessions)
self._connections[addr] = imapProtocol
return imapProtocol
def stopFactory(self):
- # say bye!
for conn, proto in self._connections.items():
- logger.debug("Closing connections for %s" % conn)
proto.close_server_connection()
def doStop(self):
- """
- Stops imap service (fetcher, factory and port).
- """
return ServerFactory.doStop(self)
@@ -182,10 +174,10 @@ def run_service(soledad_sessions, port=IMAP_PORT, factory=None):
tport = reactor.listenTCP(port, factory,
interface=interface)
except CannotListenError:
- logger.error("IMAP Service failed to start: "
- "cannot listen in port %s" % (port,))
+ log.error('IMAP Service failed to start: '
+ 'cannot listen in port %s' % (port,))
except Exception as exc:
- logger.error("Error launching IMAP service: %r" % (exc,))
+ log.error("Error launching IMAP service: %r" % (exc,))
else:
# all good.
@@ -198,7 +190,7 @@ def run_service(soledad_sessions, port=IMAP_PORT, factory=None):
# TODO use Endpoints !!!
reactor.listenTCP(manhole.MANHOLE_PORT, manhole_factory,
interface="127.0.0.1")
- logger.debug("IMAP4 Server is RUNNING in port %s" % (port,))
+ log.debug('IMAP4 Server is RUNNING in port %s' % (port,))
emit_async(catalog.IMAP_SERVICE_STARTED, str(port))
# FIXME -- change service signature
diff --git a/src/leap/bitmask/mail/incoming/service.py b/src/leap/bitmask/mail/incoming/service.py
index 9ed76a09..45d0e398 100644
--- a/src/leap/bitmask/mail/incoming/service.py
+++ b/src/leap/bitmask/mail/incoming/service.py
@@ -164,7 +164,8 @@ class IncomingMail(Service):
Calls a deferred that will execute the fetch callback.
"""
def _sync_errback(failure):
- self.log.failure('Error while fetching incoming mail')
+ self.log.error(
+ 'Error while fetching incoming mail {0!r}'.format(failure))
def syncSoledadCallback(_):
# XXX this should be moved to adaptors
@@ -219,7 +220,8 @@ class IncomingMail(Service):
# synchronize incoming mail
def _errback(self, failure):
- self.log.failure('Error while processing incoming mail')
+ self.log.error(
+ 'Error while processing incoming mail {0!r}'.format(failure))
def _sync_soledad(self):
"""
@@ -234,7 +236,7 @@ class IncomingMail(Service):
def _handle_invalid_auth_token_error(failure):
failure.trap(InvalidAuthTokenError)
- self.log.warn('sync failed because token is invalid: %r' % failure)
+ self.log.warn('Sync failed because token is invalid: %r' % failure)
self.stopService()
emit_async(catalog.SOLEDAD_INVALID_AUTH_TOKEN, self._userid)
@@ -338,7 +340,7 @@ class IncomingMail(Service):
return self._process_decrypted_doc(doc, decrdata)
def log_doc_id_and_call_errback(failure):
- self.log.failure(
+ self.log.error(
'_decrypt_doc: Error decrypting document with '
'ID %s' % doc.doc_id)
@@ -368,8 +370,10 @@ class IncomingMail(Service):
# the deferreds that would process an individual document
try:
msg = json_loads(data)
- except (UnicodeError, ValueError):
- self.log.failure("Error while decrypting %s" % (doc.doc_id,))
+ except (UnicodeError, ValueError) as exc:
+ self.log.error('Error while decrypting %s' %
+ (doc.doc_id,))
+ self.log.error(str(exc))
# we flag the message as "with decrypting errors",
# to avoid further decryption attempts during sync
@@ -764,12 +768,13 @@ class IncomingMail(Service):
% (url,))
elif failure.check(keymanager_errors.KeyAttributesDiffer):
self.log.warn("Key from OpenPGP header url %s didn't "
- "match the from address %s"
- % (url, address))
+ "match the from address %s"
+ % (url, address))
else:
- self.log.warn("An error has ocurred adding key from "
- "OpenPGP header url %s for %s: %s" %
- (url, address, failure.getErrorMessage()))
+ self.log.warn(
+ "An error has ocurred adding key from "
+ "OpenPGP header url %s for %s: %s" %
+ (url, address, failure.getErrorMessage()))
return False
d = self._keymanager.fetch_key(address, url)
@@ -804,7 +809,7 @@ class IncomingMail(Service):
def failed_put_key(failure):
self.log.info("An error has ocurred adding attached key for %s: %s"
- % (address, failure.getErrorMessage()))
+ % (address, failure.getErrorMessage()))
return False
deferreds = []
diff --git a/src/leap/bitmask/mail/mail.py b/src/leap/bitmask/mail/mail.py
index 9f60ff00..8cc01e27 100644
--- a/src/leap/bitmask/mail/mail.py
+++ b/src/leap/bitmask/mail/mail.py
@@ -43,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 = Logger()
+log = Logger()
# TODO LIST
@@ -98,7 +98,7 @@ def _encode_payload(payload, ctype=""):
if isinstance(payload, unicode):
payload = payload.encode(charset)
except UnicodeError as exc:
- logger.error(
+ log.error(
"Unicode error, using 'replace'. {0!r}".format(exc))
payload = payload.encode(charset, 'replace')
return payload
@@ -122,13 +122,17 @@ def _unpack_headers(headers_dict):
class MessagePart(object):
+
# TODO This class should be better abstracted from the data model.
# TODO support arbitrarily nested multiparts (right now we only support
# the trivial case)
+
"""
Represents a part of a multipart MIME Message.
"""
+ log = Logger()
+
def __init__(self, part_map, cdocs=None, nested=False):
"""
:param part_map: a dictionary mapping the subparts for
@@ -191,7 +195,7 @@ class MessagePart(object):
try:
part_map = sub_pmap[str(part)]
except KeyError:
- logger.debug("getSubpart for %s: KeyError" % (part,))
+ self.log.debug('get_subpart for %s: KeyError' % (part,))
raise IndexError
return MessagePart(part_map, cdocs=self._cdocs, nested=True)
@@ -203,6 +207,7 @@ class MessagePart(object):
class Message(object):
+
"""
Represents a single message, and gives access to all its attributes.
"""
@@ -325,6 +330,7 @@ class Flagsmode(object):
class MessageCollection(object):
+
"""
A generic collection of messages. It can be messages sharing the same
mailbox, tag, the result of a given query, or just a bunch of ids for
@@ -340,6 +346,8 @@ class MessageCollection(object):
instance or proxy, for instance).
"""
+ log = Logger()
+
# TODO LIST
# [ ] look at IMessageSet methods
# [ ] make constructor with a per-instance deferredLock to use on
@@ -438,7 +446,7 @@ class MessageCollection(object):
d.addCallback(
lambda uid: self.get_message_by_uid(
uid, get_cdocs=get_cdocs))
- d.addErrback(logger.error)
+ d.addErrback(self.log.error('Error getting msg by seq'))
return d
def get_message_by_uid(self, uid, absolute=True, get_cdocs=False):
@@ -611,7 +619,7 @@ class MessageCollection(object):
headers = lowerdict(msg.get_headers())
moz_draft_hdr = "X-Mozilla-Draft-Info"
if moz_draft_hdr.lower() in headers:
- logger.debug("setting fast notify to False, Draft detected")
+ self.log.debug('Setting fast notify to False, Draft detected')
notify_just_mdoc = False
if notify_just_mdoc:
@@ -635,9 +643,9 @@ class MessageCollection(object):
# --- BUG -----------------------------------------
# XXX watch out, sometimes mdoc doesn't have doc_id
# but it has future_id. Should be solved already.
- logger.error("BUG: (please report) Null doc_id for "
- "document %s" %
- (wrapper.mdoc.serialize(),))
+ self.log.error('BUG: (please report) Null doc_id for '
+ 'document %s' %
+ (wrapper.mdoc.serialize(),))
return defer.succeed("mdoc_id not inserted")
# XXX BUG -----------------------------------------
@@ -656,7 +664,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(logger.error)
+ d.addErrback(lambda f: self.log.error('Error adding msg!'))
return d
@@ -743,7 +751,6 @@ 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(logger.error)
d.addCallback(log_result)
return d
@@ -801,7 +808,6 @@ class MessageCollection(object):
self.store, self.mbox_uuid)
mdocs_deleted.addCallback(get_uid_list)
mdocs_deleted.addCallback(delete_uid_entries)
- 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 bd578ed2..a3b8d005 100644
--- a/src/leap/bitmask/mail/outgoing/service.py
+++ b/src/leap/bitmask/mail/outgoing/service.py
@@ -55,11 +55,6 @@ 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):
@@ -99,6 +94,8 @@ class OutgoingMail(object):
Sends Outgoing Mail, encrypting and signing if needed.
"""
+ log = Logger()
+
def __init__(self, from_address, keymanager, cert, key, host, port,
bouncer=None):
"""
@@ -167,7 +164,7 @@ class OutgoingMail(object):
"""
dest_addrstr = smtp_sender_result[1][0][0]
fromaddr = self._from_address
- logger.info('Message sent from %s to %s' % (fromaddr, dest_addrstr))
+ self.log.info('Message sent from %s to %s' % (fromaddr, dest_addrstr))
emit_async(catalog.SMTP_SEND_MESSAGE_SUCCESS,
fromaddr, dest_addrstr)
@@ -190,7 +187,7 @@ class OutgoingMail(object):
# temporal error. We might want to notify the permanent errors
# differently.
- logger.error(failure)
+ self.log.error('Error while sending: {0!r}'.format(failure))
if self._bouncer:
self._bouncer.bounce_message(
@@ -208,7 +205,7 @@ class OutgoingMail(object):
:type encrypt_and_sign_result: tuple
"""
message, recipient = encrypt_and_sign_result
- logger.info(
+ self.log.info(
'Connecting to SMTP server %s:%s' % (self._host, self._port))
msg = message.as_string(False)
@@ -302,7 +299,7 @@ class OutgoingMail(object):
def if_key_not_found_send_unencrypted(failure, message):
failure.trap(KeyNotFound, KeyAddressMismatch)
- logger.info('Will send unencrypted message to %s.' % to_address)
+ self.log.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)
@@ -312,8 +309,8 @@ class OutgoingMail(object):
emit_async(catalog.SMTP_END_SIGN, self._from_address)
return newmsg, recipient
- logger.info("Will encrypt the message with %s and sign with %s."
- % (to_address, from_address))
+ self.log.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 e602b6b6..cb592689 100644
--- a/src/leap/bitmask/mail/rfc3156.py
+++ b/src/leap/bitmask/mail/rfc3156.py
@@ -34,7 +34,7 @@ from email.generator import (
_make_boundary,
)
-logger = Logger()
+log = Logger()
#
# A generator that solves http://bugs.python.org/issue14983
@@ -166,7 +166,7 @@ def encode_base64(msg):
except KeyError:
msg['Content-Transfer-Encoding'] = 'base64'
elif encoding is not 'base64':
- logger.error('Unknown content-transfer-encoding: %s' % encoding)
+ log.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 90baf668..e69de29b 100644
--- a/src/leap/bitmask/mail/smtp/__init__.py
+++ b/src/leap/bitmask/mail/smtp/__init__.py
@@ -1,71 +0,0 @@
-# -*- coding: utf-8 -*-
-# __init__.py
-# Copyright (C) 2013-2016 LEAP
-#
-# This program is free software: you can redistribute it and/or modify
-# it under the terms of the GNU General Public License as published by
-# the Free Software Foundation, either version 3 of the License, or
-# (at your option) any later version.
-#
-# This program is distributed in the hope that it will be useful,
-# but WITHOUT ANY WARRANTY; without even the implied warranty of
-# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
-# GNU General Public License for more details.
-#
-# You should have received a copy of the GNU General Public License
-# along with this program. If not, see <http://www.gnu.org/licenses/>.
-"""
-SMTP gateway helper function.
-"""
-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 = Logger()
-
-SMTP_PORT = 2013
-
-
-def run_service(soledad_sessions, keymanager_sessions, sendmail_opts,
- port=SMTP_PORT, factory=None):
- """
- Main entry point to run the service from the client.
-
- :param soledad_sessions: a dict-like object, containing instances
- of a Store (soledad instances), indexed by userid.
- :param keymanager_sessions: a dict-like object, containing instances
- of Keymanager, indexed by userid.
- :param sendmail_opts: a dict-like object of sendmailOptions.
-
- :returns: the port as returned by the reactor when starts listening, and
- the factory for the protocol.
- :rtype: tuple
- """
- if not factory:
- factory = SMTPFactory(soledad_sessions, keymanager_sessions,
- sendmail_opts)
-
- try:
- interface = "localhost"
- # don't bind just to localhost if we are running on docker since we
- # won't be able to access smtp from the host
- if os.environ.get("LEAP_DOCKERIZED"):
- interface = ''
-
- # TODO Use Endpoints instead --------------------------------
- tport = reactor.listenTCP(port, factory, interface=interface)
- emit_async(catalog.SMTP_SERVICE_STARTED, str(port))
-
- return tport, factory
- except CannotListenError:
- logger.error("SMTP Service failed to start: "
- "cannot listen in port %s" % port)
- emit_async(catalog.SMTP_SERVICE_FAILED_TO_START, str(port))
- except Exception as exc:
- logger.error("Unhandled error while launching smtp gateway service")
- logger.error('%r' % exc)
diff --git a/src/leap/bitmask/mail/smtp/gateway.py b/src/leap/bitmask/mail/smtp/gateway.py
index b1fafadd..08d59e11 100644
--- a/src/leap/bitmask/mail/smtp/gateway.py
+++ b/src/leap/bitmask/mail/smtp/gateway.py
@@ -56,8 +56,6 @@ generator.Generator = RFC3156CompliantGenerator
LOCAL_FQDN = "bitmask.local"
-logger = Logger()
-
@implementer(IRealm)
class LocalSMTPRealm(object):
@@ -221,10 +219,13 @@ class SMTPFactory(protocol.ServerFactory):
@implementer(smtp.IMessageDelivery)
class SMTPDelivery(object):
+
"""
Validate email addresses and handle message delivery.
"""
+ log = Logger()
+
def __init__(self, userid, keymanager, encrypted_only, outgoing_mail):
"""
Initialize the SMTP delivery object.
@@ -298,7 +299,7 @@ class SMTPDelivery(object):
# verify if recipient key is available in keyring
def found(_):
- logger.debug("Accepting mail for %s..." % user.dest.addrstr)
+ self.log.debug('Accepting mail for %s...' % user.dest.addrstr)
emit_async(catalog.SMTP_RECIPIENT_ACCEPTED_ENCRYPTED,
self._userid, user.dest.addrstr)
@@ -310,7 +311,7 @@ class SMTPDelivery(object):
emit_async(catalog.SMTP_RECIPIENT_REJECTED, self._userid,
user.dest.addrstr)
raise smtp.SMTPBadRcpt(user.dest.addrstr)
- logger.warn(
+ self.log.warn(
'Warning: will send an unencrypted message (because '
'"encrypted_only" is set to False).')
emit_async(
@@ -344,7 +345,7 @@ class SMTPDelivery(object):
# accept mail from anywhere. To reject an address, raise
# smtp.SMTPBadSender here.
if str(origin) != str(self._userid):
- logger.error(
+ self.log.error(
"Rejecting sender {0}, expected {1}".format(origin,
self._userid))
raise smtp.SMTPBadSender(origin)
@@ -362,6 +363,7 @@ class EncryptedMessage(object):
recipient.
"""
implements(smtp.IMessage)
+ log = Logger()
def __init__(self, user, outgoing_mail):
"""
@@ -396,7 +398,7 @@ class EncryptedMessage(object):
:returns: a deferred
"""
- logger.debug("Message data complete.")
+ self.log.debug('Message data complete.')
self._lines.append('') # add a trailing newline
raw_mail = '\r\n'.join(self._lines)
@@ -406,8 +408,7 @@ class EncryptedMessage(object):
"""
Log an error when the connection is lost.
"""
- logger.error("Connection lost unexpectedly!")
- logger.error()
+ self.log.error('Connection lost unexpectedly!')
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 48e6865b..6fd000ce 100644
--- a/src/leap/bitmask/mail/smtp/service.py
+++ b/src/leap/bitmask/mail/smtp/service.py
@@ -26,7 +26,7 @@ from twisted.logger import Logger
from leap.common.events import emit_async, catalog
from leap.bitmask.mail.smtp.gateway import SMTPFactory
-logger = Logger()
+log = Logger()
SMTP_PORT = 2013
@@ -65,9 +65,9 @@ def run_service(soledad_sessions, keymanager_sessions, sendmail_opts,
return tport, factory
except CannotListenError:
- logger.error("STMP Service failed to start: "
- "cannot listen in port %s" % port)
+ log.error('STMP Service failed to start: '
+ 'cannot listen in port %s' % port)
emit_async(catalog.SMTP_SERVICE_FAILED_TO_START, str(port))
except Exception as exc:
- logger.error("Unhandled error while launching smtp gateway service")
- logger.error('%r' % exc)
+ log.error('Unhandled error while launching smtp gateway service')
+ log.error('%r' % exc)
diff --git a/src/leap/bitmask/mail/sync_hooks.py b/src/leap/bitmask/mail/sync_hooks.py
index de3a0c1a..e8f25e88 100644
--- a/src/leap/bitmask/mail/sync_hooks.py
+++ b/src/leap/bitmask/mail/sync_hooks.py
@@ -14,12 +14,14 @@
#
# You should have received a copy of the GNU General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
+
"""
Soledad PostSync Hooks.
Process every new document of interest after every soledad synchronization,
using the hooks that soledad exposes via plugins.
"""
+
from re import compile as regex_compile
from zope.interface import implements
@@ -30,7 +32,7 @@ from twisted.logger import Logger
from leap.bitmask.mail import constants
from leap.soledad.client.interfaces import ISoledadPostSyncPlugin
-logger = Logger()
+log = Logger()
def _get_doc_type_preffix(s):
@@ -38,6 +40,7 @@ def _get_doc_type_preffix(s):
class MailProcessingPostSyncHook(object):
+
implements(IPlugin, ISoledadPostSyncPlugin)
META_DOC_PREFFIX = _get_doc_type_preffix(constants.METAMSGID)
@@ -56,7 +59,7 @@ class MailProcessingPostSyncHook(object):
for doc_id in doc_id_list:
if _get_doc_type_preffix(doc_id) in self.watched_doc_types:
- logger.info("Mail post-sync hook: processing %s" % doc_id)
+ log.info("Mail post-sync hook: processing %s" % doc_id)
process_fun(doc_id)
return defer.gatherResults(self._processing_deferreds)
@@ -77,7 +80,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))
+ log.debug('Making index table for %s:%s' % (mbox_uuid, chash))
index_docid = constants.METAMSGID.format(
mbox_uuid=mbox_uuid.replace('-', '_'),
chash=chash)
@@ -91,7 +94,7 @@ class MailProcessingPostSyncHook(object):
def _process_queued_docs(self):
assert(self._has_configured_account())
pending = self._pending_docs
- logger.info("Mail post-sync hook: processing queued docs")
+ log.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 92bf4d34..fa4c08eb 100644
--- a/src/leap/bitmask/mail/testing/imap.py
+++ b/src/leap/bitmask/mail/testing/imap.py
@@ -38,7 +38,7 @@ from leap.bitmask.mail.testing.common import SoledadTestMixin
TEST_USER = "testuser@leap.se"
TEST_PASSWD = "1234"
-logger = Logger()
+log = Logger()
#
@@ -182,7 +182,7 @@ class IMAP4HelperMixin(SoledadTestMixin):
self.client.transport.loseConnection()
self.server.transport.loseConnection()
if hasattr(self, 'function'):
- logger.error(failure, "Problem with %r" % (self.function,))
+ log.error("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 05f1c5b3..c5154cd0 100644
--- a/src/leap/bitmask/util.py
+++ b/src/leap/bitmask/util.py
@@ -28,7 +28,7 @@ from leap.common.files import which
STANDALONE = getattr(sys, 'frozen', False)
-logger = Logger()
+log = Logger()
def here(module=None):
@@ -108,7 +108,7 @@ def get_gpg_bin_path():
gpgbin = path
break
except IndexError as e:
- logger.debug("couldn't find the gpg binary!: %s" % (e,))
+ log.debug("Couldn't find the gpg binary!: %s" % (e,))
if gpgbin is not None:
return gpgbin
@@ -124,8 +124,8 @@ def get_gpg_bin_path():
gpgbin = opt
break
except IndexError as e:
- logger.debug("couldn't find the gpg1 binary!: %s" % (e,))
+ log.debug("Couldn't find the gpg1 binary!: %s" % (e,))
if gpgbin is None:
- logger.debug("Could not find gpg1 binary")
+ log.debug("Could not find gpg1 binary")
return gpgbin
diff --git a/src/leap/bitmask/vpn/_control.py b/src/leap/bitmask/vpn/_control.py
index 6d4db965..85e4911c 100644
--- a/src/leap/bitmask/vpn/_control.py
+++ b/src/leap/bitmask/vpn/_control.py
@@ -8,7 +8,7 @@ from twisted.logger import Logger
from .process import VPNProcess
from .constants import IS_MAC
-logger = Logger()
+log = Logger()
# NOTE: We need to set a bigger poll time in OSX because it seems
# openvpn malfunctions when you ask it a lot of things in a short
@@ -47,7 +47,7 @@ class VPNControl(object):
self._port = socket_port
def start(self):
- logger.debug('VPN: start')
+ log.debug('VPN: start')
self._user_stopped = False
self._stop_pollers()
@@ -58,13 +58,13 @@ class VPNControl(object):
restartfun=self.restart)
if vpnproc.get_openvpn_process():
- logger.info("Another vpn process is running. Will try to stop it.")
+ log.info('Another vpn process is running. Will try to stop it.')
vpnproc.stop_if_already_running()
try:
cmd = vpnproc.getCommand()
except Exception as e:
- logger.error("Error while getting vpn command... {0!r}".format(e))
+ log.error('Error while getting vpn command... {0!r}'.format(e))
raise
env = os.environ
@@ -118,7 +118,7 @@ class VPNControl(object):
reactor.callLater(
self.TERMINATE_WAIT, self._kill_if_left_alive)
else:
- logger.debug("VPN is not running.")
+ log.debug('VPN is not running.')
return True
@@ -153,7 +153,7 @@ class VPNControl(object):
"""
self._stop_pollers()
if self._vpnproc is None:
- logger.debug("There's no vpn process running to kill.")
+ log.debug("There's no vpn process running to kill.")
else:
self._vpnproc.aborted = True
self._vpnproc.killProcess()
@@ -168,10 +168,9 @@ class VPNControl(object):
"""
while tries < self.TERMINATE_MAXTRIES:
if self._vpnproc.transport.pid is None:
- logger.debug("Process has been happily terminated.")
return
else:
- logger.debug("Process did not die, waiting...")
+ log.debug('Process did not die, waiting...')
tries += 1
reactor.callLater(self.TERMINATE_WAIT,
@@ -179,11 +178,11 @@ class VPNControl(object):
return
# after running out of patience, we try a killProcess
- logger.debug("Process did not died. Sending a SIGKILL.")
+ log.debug('Process did not die. Sending a SIGKILL.')
try:
self._killit()
except OSError:
- logger.error("Could not kill process!")
+ log.error('Could not kill process!')
def _start_pollers(self):
"""
diff --git a/src/leap/bitmask/vpn/_management.py b/src/leap/bitmask/vpn/_management.py
index 8bf3cc78..453b042c 100644
--- a/src/leap/bitmask/vpn/_management.py
+++ b/src/leap/bitmask/vpn/_management.py
@@ -18,9 +18,6 @@ except ImportError:
from ._telnet import UDSTelnet
-logger = Logger()
-
-
class OpenVPNAlreadyRunning(Exception):
message = ("Another openvpn instance is already running, and could "
"not be stopped.")
@@ -41,6 +38,7 @@ class VPNManagement(object):
zcat `dpkg -L openvpn | grep management`
"""
+ log = Logger()
# Timers, in secs
CONNECTION_RETRY_TIME = 1
@@ -56,7 +54,7 @@ class VPNManagement(object):
try:
self._tn.read_eager()
except EOFError:
- logger.debug("Could not read from socket. Assuming it died.")
+ self.log.debug('Could not read from socket. Assuming it died.')
return
def _send_command(self, command, until=b"END"):
@@ -89,23 +87,21 @@ class VPNManagement(object):
except socket.error:
# XXX should get a counter and repeat only
# after mod X times.
- logger.warn('socket error (command was: "%s")' % (command,))
+ self.log.warn('Socket error (command was: "%s")' % (command,))
self._close_management_socket(announce=False)
- logger.debug('trying to connect to management again')
+ self.log.debug('Trying to connect to management again')
self.try_to_connect_to_management(max_retries=5)
return []
- # XXX should move this to a errBack!
except Exception as e:
- logger.warn("Error sending command %s: %r" %
- (command, e))
+ self.log.warn("Error sending command %s: %r" %
+ (command, e))
return []
def _close_management_socket(self, announce=True):
"""
Close connection to openvpn management interface.
"""
- logger.debug('closing socket')
if announce:
self._tn.write("quit\n")
self._tn.read_all()
@@ -141,9 +137,8 @@ class VPNManagement(object):
if self._tn:
self._tn.read_eager()
- # XXX move this to the Errback
except Exception as e:
- logger.warn("Could not connect to OpenVPN yet: %r" % (e,))
+ self.log.warn('Could not connect to OpenVPN yet: %r' % (e,))
self._tn = None
def _connectCb(self, *args):
@@ -152,10 +147,8 @@ class VPNManagement(object):
:param args: not used
"""
- if self._tn:
- logger.info('Connected to management')
- else:
- logger.debug('Cannot connect to management...')
+ if not self._tn:
+ self.log.warn('Cannot connect to management...')
def _connectErr(self, failure):
"""
@@ -163,7 +156,7 @@ class VPNManagement(object):
:param failure: Failure
"""
- logger.warn(failure)
+ self.log.failure('Error while connecting to management!')
def connect_to_management(self, host, port):
"""
@@ -200,17 +193,17 @@ class VPNManagement(object):
:type retry: int
"""
if max_retries and retry > max_retries:
- logger.warn("Max retries reached while attempting to connect "
- "to management. Aborting.")
+ self.log.warn(
+ 'Max retries reached while attempting to connect '
+ 'to management. Aborting.')
self.aborted = True
return
# _alive flag is set in the VPNProcess class.
if not self._alive:
- logger.debug('Tried to connect to management but process is '
- 'not alive.')
+ self.log.debug('Tried to connect to management but process is '
+ 'not alive.')
return
- logger.debug('trying to connect to management')
if not self.aborted and not self.is_connected():
self.connect_to_management(self._socket_host, self._socket_port)
reactor.callLater(
@@ -268,7 +261,7 @@ class VPNManagement(object):
try:
text, value = parts
except ValueError:
- logger.debug("Could not parse %s" % parts)
+ self.log.debug('Could not parse %s' % parts)
return
# text can be:
# "TUN/TAP read bytes"
@@ -329,13 +322,14 @@ class VPNManagement(object):
under normal circumstances, we should be able to delete.
"""
if self._socket_port == "unix":
- logger.debug('cleaning socket file temp folder')
+ self.log.debug('Cleaning socket file temp folder')
tempfolder = _first(os.path.split(self._socket_host))
if tempfolder and os.path.isdir(tempfolder):
try:
shutil.rmtree(tempfolder)
except OSError:
- logger.error('could not delete tmpfolder %s' % tempfolder)
+ self.log.error(
+ 'Could not delete tmpfolder %s' % tempfolder)
def get_openvpn_process(self):
"""
@@ -380,11 +374,11 @@ class VPNManagement(object):
"""
process = self.get_openvpn_process()
if not process:
- logger.debug('Could not find openvpn process while '
- 'trying to stop it.')
+ self.log.debug('Could not find openvpn process while '
+ 'trying to stop it.')
return
- logger.debug("OpenVPN is already running, trying to stop it...")
+ self.log.debug('OpenVPN is already running, trying to stop it...')
cmdline = process.cmdline
manag_flag = "--management"
@@ -400,16 +394,16 @@ class VPNManagement(object):
return "leap" in s and "providers" in s
if not any(map(smellslikeleap, cmdline)):
- logger.debug("We cannot stop this instance since we do not "
- "recognise it as a leap invocation.")
+ self.log.debug("We cannot stop this instance since we do not "
+ "recognise it as a leap invocation.")
raise AlienOpenVPNAlreadyRunning
try:
index = cmdline.index(manag_flag)
host = cmdline[index + 1]
port = cmdline[index + 2]
- logger.debug("Trying to connect to %s:%s"
- % (host, port))
+ self.log.debug("Trying to connect to %s:%s"
+ % (host, port))
self.connect_to_management(host, port)
# XXX this has a problem with connections to different
@@ -421,19 +415,18 @@ class VPNManagement(object):
# However, that should be a rare case right now.
self._send_command("signal SIGTERM")
self._close_management_socket(announce=True)
- except (Exception, AssertionError) as e:
- logger.warn("Problem trying to terminate OpenVPN: %r"
- % (e,))
+ except (Exception, AssertionError):
+ self.log.failure('Problem trying to terminate OpenVPN')
else:
- logger.debug("Could not find the expected openvpn command line.")
+ self.log.debug('Could not find the expected openvpn command line.')
process = self.get_openvpn_process()
if process is None:
- logger.debug("Successfully finished already running "
- "openvpn process.")
+ self.log.debug('Successfully finished already running '
+ 'openvpn process.')
return True
else:
- logger.warn("Unable to terminate OpenVPN")
+ self.log.warn('Unable to terminate OpenVPN')
raise OpenVPNAlreadyRunning
diff --git a/src/leap/bitmask/vpn/launcher.py b/src/leap/bitmask/vpn/launcher.py
index 3006d6da..fa9923a8 100644
--- a/src/leap/bitmask/vpn/launcher.py
+++ b/src/leap/bitmask/vpn/launcher.py
@@ -33,7 +33,7 @@ from leap.bitmask.vpn.constants import IS_LINUX
from leap.bitmask.vpn.utils import force_eval
-logger = Logger()
+log = Logger()
flags_STANDALONE = False
@@ -62,18 +62,18 @@ def _has_updown_scripts(path, warn=True):
"""
is_file = os.path.isfile(path)
if warn and not is_file:
- logger.error("Could not find up/down script %s. "
- "Might produce DNS leaks." % (path,))
+ log.error('Could not find up/down script %s. '
+ 'Might produce DNS leaks.' % (path,))
# XXX check if applies in win
is_exe = False
try:
is_exe = (stat.S_IXUSR & os.stat(path)[stat.ST_MODE] != 0)
except OSError as e:
- logger.warn("%s" % (e,))
+ log.warn("%s" % (e,))
if warn and not is_exe:
- logger.error("Up/down script %s is not executable. "
- "Might produce DNS leaks." % (path,))
+ log.error('Up/down script %s is not executable. '
+ 'Might produce DNS leaks.' % (path,))
return is_file and is_exe
@@ -91,8 +91,8 @@ def _has_other_files(path, warn=True):
"""
is_file = os.path.isfile(path)
if warn and not is_file:
- logger.warning("Could not find file during checks: %s. " % (
- path,))
+ log.warn('Could not find file during checks: %s. ' % (
+ path,))
return is_file
@@ -109,6 +109,7 @@ class VPNLauncher(object):
PREFERRED_PORTS = ("443", "80", "53", "1194")
+ # FIXME -- dead code?
@classmethod
@abstractmethod
def get_gateways(kls, vpnconfig, providerconfig):
@@ -138,7 +139,7 @@ class VPNLauncher(object):
gws = [gateway_conf]
if not gws:
- logger.error('No gateway was found!')
+ log.error('No gateway was found!')
raise VPNLauncherException('No gateway was found!')
for idx, gw in enumerate(gws):
@@ -156,7 +157,7 @@ class VPNLauncher(object):
gateways.append((gw, the_port))
- logger.debug("Using gateways (ip, port): {0!r}".format(gateways))
+ log.debug('Using gateways (ip, port): {0!r}'.format(gateways))
return gateways
@classmethod
@@ -198,8 +199,8 @@ class VPNLauncher(object):
openvpn_path = force_eval(kls.OPENVPN_BIN_PATH)
if not os.path.isfile(openvpn_path):
- logger.warning("Could not find openvpn bin in path %s" % (
- openvpn_path))
+ log.warn('Could not find openvpn bin in path %s' % (
+ openvpn_path))
raise OpenVPNNotFoundException()
args = []
@@ -321,11 +322,6 @@ class VPNLauncher(object):
:rtype: list
"""
- # leap_assert(kls.OTHER_FILES is not None,
- # "Need to define OTHER_FILES for this particular "
- # "auncher before calling this method")
-
- # TODO assert vs except?
if kls.OTHER_FILES is None:
raise Exception(
"Need to define OTHER_FILES for this particular "
diff --git a/src/leap/bitmask/vpn/privilege.py b/src/leap/bitmask/vpn/privilege.py
index 135acbb8..9666a943 100644
--- a/src/leap/bitmask/vpn/privilege.py
+++ b/src/leap/bitmask/vpn/privilege.py
@@ -31,7 +31,7 @@ from abc import ABCMeta, abstractmethod
from twisted.logger import Logger
from twisted.python.procutils import which
-logger = Logger()
+log = Logger()
flags_STANDALONE = False
@@ -71,8 +71,8 @@ def is_missing_policy_permissions():
if not policy_checker:
# it is true that we miss permission to escalate
# privileges without asking for password each time.
- logger.debug("we could not find a policy checker implementation "
- "for %s" % (_system,))
+ log.debug('we could not find a policy checker implementation '
+ 'for %s' % (_system,))
return True
return policy_checker().is_missing_policy_permissions()
@@ -146,18 +146,15 @@ class LinuxPolicyChecker(PolicyChecker):
time.sleep(2)
if self.is_up():
pkexec_possibilities = which(self.PKEXEC_BIN)
- # leap_assert(len(pkexec_possibilities) > 0,
- # "We couldn't find pkexec")
if not pkexec_possibilities:
- logger.error("We couldn't find pkexec")
raise Exception("We couldn't find pkexec")
return pkexec_possibilities
else:
- logger.warn("No polkit auth agent found. pkexec " +
- "will use its own auth agent.")
+ log.warn('No polkit auth agent found. pkexec ' +
+ 'will use its own auth agent.')
raise NoPolkitAuthAgentAvailable()
else:
- logger.warn("System has no pkexec")
+ log.warn('System has no pkexec')
raise NoPkexecAvailable()
@classmethod
@@ -178,11 +175,11 @@ class LinuxPolicyChecker(PolicyChecker):
# will do "sh -c 'foo'", so if we do not quoute it we'll end
# up with a invocation to the python interpreter. And that
# is bad.
- logger.debug("Trying to launch polkit agent")
+ log.debug('Trying to launch polkit agent')
subprocess.call(["python -m leap.bitmask.util.polkit_agent"],
shell=True, env=env)
- except Exception as exc:
- logger.error(str(exc))
+ except Exception:
+ log.failure('Error while launching vpn')
@classmethod
def is_up(self):
diff --git a/src/leap/bitmask/vpn/process.py b/src/leap/bitmask/vpn/process.py
index 6096a473..e136e5bb 100644
--- a/src/leap/bitmask/vpn/process.py
+++ b/src/leap/bitmask/vpn/process.py
@@ -32,20 +32,21 @@ from leap.bitmask.vpn.utils import get_vpn_launcher
from leap.bitmask.vpn import _status
from leap.bitmask.vpn import _management
-logger = Logger()
-
# OpenVPN verbosity level - from flags.py
OPENVPN_VERBOSITY = 1
class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
+
"""
A ProcessProtocol class that can be used to spawn a process that will
launch openvpn and connect to its management interface to control it
programmatically.
"""
+ log = Logger()
+
# TODO do we really need the vpnconfig/providerconfig objects in here???
def __init__(self, vpnconfig, providerconfig, socket_host, socket_port,
@@ -123,7 +124,7 @@ class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
line = data[:-1]
if 'SIGTERM[soft,ping-restart]' in line:
self.restarting = True
- logger.info(line)
+ self.log.info(line)
self._status.watch(line)
def processExited(self, failure):
@@ -140,9 +141,9 @@ class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
elif err == internet_error.ProcessTerminated:
status, errmsg = 'failure', failure.value.exitCode
if errmsg:
- logger.debug("processExited, status %d" % (errmsg,))
+ self.log.debug('processExited, status %d' % (errmsg,))
else:
- logger.warn('%r' % failure.value)
+ self.log.warn('%r' % failure.value)
self._status.set_status(status, errmsg)
self._alive = False
@@ -156,9 +157,9 @@ class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
"""
exit_code = reason.value.exitCode
if isinstance(exit_code, int):
- logger.debug("processEnded, status %d" % (exit_code,))
+ self.log.debug('processEnded, status %d' % (exit_code,))
if self.restarting:
- logger.debug('Restarting VPN process')
+ self.log.debug('Restarting VPN process')
reactor.callLater(2, self._restartfun)
# polling
@@ -202,8 +203,8 @@ class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
if not isinstance(c, str):
command[i] = c.encode(encoding)
- logger.debug("Running VPN with command: ")
- logger.debug("{0}".format(" ".join(command)))
+ self.log.debug("Running VPN with command: ")
+ self.log.debug("{0}".format(" ".join(command)))
return command
def getGateways(self):
@@ -227,4 +228,4 @@ class VPNProcess(protocol.ProcessProtocol, _management.VPNManagement):
try:
self.transport.signalProcess('KILL')
except internet_error.ProcessExitedAlready:
- logger.debug('Process Exited Already')
+ self.log.debug('Process Exited Already')