summaryrefslogtreecommitdiffstats
path: root/pykolab
diff options
context:
space:
mode:
authorLiutauras Adomaitis <adomaitis@kolabsys.com>2018-03-15 16:17:38 +0200
committerLiutauras Adomaitis <adomaitis@kolabsys.com>2018-05-17 09:56:05 +0300
commit10f1c173941d0a8df227822ca4b497398eb73760 (patch)
tree9a10c7d3fca5ffc5bf7bbfc383d01f9ac36cdaab /pykolab
parentae2ba60049a4e5c4e4ea427dfb59a63547a683ea (diff)
downloadpykolab-10f1c173941d0a8df227822ca4b497398eb73760.tar.gz
With this patch I'm trying to introduce a file-type object in logger, which could swallow everything thrown to stderr (and possibly stdout) and redirect to python logger. Python smtplib debug mode prints everything to stderr, but when wallace runs...
Summary: ...in fork mode stderr is not available (Bad file descriptor error) and thus wallace traceback when it tries to send emails Test Plan: none Reviewers: vanmeeuwen, machniak, petersen Reviewed By: vanmeeuwen Subscribers: petersen, machniak, vanmeeuwen Maniphest Tasks: T2498, T2163, T3751 Differential Revision: https://git.kolab.org/D577
Diffstat (limited to 'pykolab')
-rw-r--r--pykolab/auth/__init__.py14
-rw-r--r--pykolab/auth/ldap/__init__.py26
-rw-r--r--pykolab/cli/sieve/cmd_refresh.py2
-rw-r--r--pykolab/imap/cyrus.py13
-rw-r--r--pykolab/itip/__init__.py4
-rw-r--r--pykolab/logger.py30
-rw-r--r--pykolab/plugins/roundcubedb/__init__.py4
7 files changed, 65 insertions, 28 deletions
diff --git a/pykolab/auth/__init__.py b/pykolab/auth/__init__.py
index 84014ae..531de1e 100644
--- a/pykolab/auth/__init__.py
+++ b/pykolab/auth/__init__.py
@@ -86,7 +86,7 @@ class Auth(pykolab.base.Base):
back to the primary domain specified by the configuration.
"""
- log.debug(_("Called for domain %r") % (domain), level=9)
+ log.debug(_("Called for domain %r") % (domain), level=8)
if not self._auth == None:
return
@@ -104,7 +104,7 @@ class Auth(pykolab.base.Base):
log.debug(
_("Using section %s and domain %s") % (section,domain),
- level=9
+ level=8
)
if not self.domains == None and self.domains.has_key(domain):
@@ -113,7 +113,7 @@ class Auth(pykolab.base.Base):
log.debug(
_("Using section %s and domain %s") % (section,domain),
- level=9
+ level=8
)
log.debug(
@@ -129,7 +129,7 @@ class Auth(pykolab.base.Base):
if not conf.has_option(section, 'auth_mechanism'):
log.debug(
_("Section %s has no option 'auth_mechanism'") % (section),
- level=9
+ level=8
)
section = 'kolab'
@@ -139,12 +139,12 @@ class Auth(pykolab.base.Base):
section,
conf.get(section,'auth_mechanism')
),
- level=9
+ level=8
)
# Get the actual authentication and authorization backend.
if conf.get(section, 'auth_mechanism') == 'ldap':
- log.debug(_("Starting LDAP..."), level=9)
+ log.debug(_("Starting LDAP..."), level=8)
from pykolab.auth import ldap
self._auth = ldap.LDAP(self.domain)
@@ -153,7 +153,7 @@ class Auth(pykolab.base.Base):
self._auth = sql.SQL(self.domain)
else:
- log.debug(_("Starting LDAP..."), level=9)
+ log.debug(_("Starting LDAP..."), level=8)
from pykolab.auth import ldap
self._auth = ldap.LDAP(self.domain)
diff --git a/pykolab/auth/ldap/__init__.py b/pykolab/auth/ldap/__init__.py
index 5efa9dc..0c440da 100644
--- a/pykolab/auth/ldap/__init__.py
+++ b/pykolab/auth/ldap/__init__.py
@@ -458,6 +458,7 @@ class LDAP(pykolab.base.Base):
conn = ldap.ldapobject.ReconnectLDAPObject(
uri,
trace_level=trace_level,
+ trace_file=pykolab.logger.StderrToLogger(log),
retry_max=retry_max,
retry_delay=retry_delay
)
@@ -543,9 +544,9 @@ class LDAP(pykolab.base.Base):
self._bind()
- log.debug(_("Entry ID: %r") % (entry_id), level=9)
+ log.debug(_("Entry ID: %r") % (entry_id), level=8)
entry_dn = self.entry_dn(entry_id)
- log.debug(_("Entry DN: %r") % (entry_dn), level=9)
+ log.debug(_("Entry DN: %r") % (entry_dn), level=8)
log.debug(
_("ldap search: (%r, %r, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + %r") % (
@@ -553,7 +554,7 @@ class LDAP(pykolab.base.Base):
ldap.SCOPE_BASE,
attributes
),
- level=9
+ level=8
)
_search = self.ldap.search_ext(
@@ -854,7 +855,7 @@ class LDAP(pykolab.base.Base):
def get_latest_sync_timestamp(self):
timestamp = cache.last_modify_timestamp(self.domain)
- log.debug(_("Using timestamp %r") % (timestamp), level=9)
+ log.debug(_("Using timestamp %r") % (timestamp), level=8)
return timestamp
def list_secondary_domains(self):
@@ -1145,7 +1146,7 @@ class LDAP(pykolab.base.Base):
_("Secondary mail addresses that we want is not None: %r") % (
secondary_mail_addresses
),
- level=9
+ level=8
)
secondary_mail_addresses = list(set(secondary_mail_addresses))
@@ -1156,7 +1157,7 @@ class LDAP(pykolab.base.Base):
_("Avoiding the duplication of the primary mail " + \
"address %r in the list of secondary mail " + \
"addresses") % (primary_mail_address),
- level=9
+ level=8
)
secondary_mail_addresses.pop(
@@ -1167,14 +1168,14 @@ class LDAP(pykolab.base.Base):
_("Entry is getting secondary mail addresses: %r") % (
secondary_mail_addresses
),
- level=9
+ level=8
)
if not entry.has_key(secondary_mail_attribute):
log.debug(
_("Entry did not have any secondary mail " + \
"addresses in %r") % (secondary_mail_attribute),
- level=9
+ level=8
)
if not len(secondary_mail_addresses) == 0:
@@ -1241,7 +1242,7 @@ class LDAP(pykolab.base.Base):
)
def set_entry_attribute(self, entry_id, attribute, value):
- log.debug(_("Setting entry attribute %r to %r for %r") % (attribute, value, entry_id), level=9)
+ log.debug(_("Setting entry attribute %r to %r for %r") % (attribute, value, entry_id), level=8)
self.set_entry_attributes(entry_id, { attribute: value })
def set_entry_attributes(self, entry_id, attributes):
@@ -1375,7 +1376,7 @@ class LDAP(pykolab.base.Base):
current_ldap_quota,
default_quota
),
- level=9
+ level=8
)
new_quota = conf.plugins.exec_hook("set_user_folder_quota", kw={
@@ -2637,7 +2638,7 @@ class LDAP(pykolab.base.Base):
args,
kw
),
- level=9
+ level=8
)
# Typical for Persistent Change Control EntryChangeNotification
@@ -2718,7 +2719,7 @@ class LDAP(pykolab.base.Base):
#
# rcpt_addrs = self.recipient_policy(entry)
#
-# log.debug(_("Recipient Addresses: %r") % (rcpt_addrs), level=9)
+# log.debug(_("Recipient Addresses: %r") % (rcpt_addrs), level=8)
#
# for key in rcpt_addrs.keys():
# entry[key] = rcpt_addrs[key]
@@ -2950,6 +2951,7 @@ class LDAP(pykolab.base.Base):
'/var/lib/kolab/syncrepl_%s.db' % (self.domain),
ldap_url.initializeUrl(),
trace_level=2,
+ trace_file=pykolab.logger.StderrToLogger(log),
callback=self._synchronize_callback
)
diff --git a/pykolab/cli/sieve/cmd_refresh.py b/pykolab/cli/sieve/cmd_refresh.py
index 3d6b1d9..b784eac 100644
--- a/pykolab/cli/sieve/cmd_refresh.py
+++ b/pykolab/cli/sieve/cmd_refresh.py
@@ -356,7 +356,7 @@ def execute(*args, **kw):
mgmt_script = mgmt_script.__str__()
- log.debug(_("MANAGEMENT script for user %s contents: %r") % (address,mgmt_script), level=9)
+ log.debug(_("MANAGEMENT script for user %s contents: %r") % (address,mgmt_script), level=8)
result = sieveclient.putscript("MANAGEMENT", mgmt_script)
diff --git a/pykolab/imap/cyrus.py b/pykolab/imap/cyrus.py
index 27f889b..9907c44 100644
--- a/pykolab/imap/cyrus.py
+++ b/pykolab/imap/cyrus.py
@@ -90,6 +90,11 @@ class Cyrus(cyruslib.CYRUS):
if conf.debuglevel > 8:
self.VERBOSE = True
self.m.debug = 5
+ sl = pykolab.logger.StderrToLogger(log)
+ # imaplib debug outputs everything to stderr. Redirect to Logger
+ sys.stderr = sl
+ # cyruslib debug outputs everything to LOGFD. Redirect to Logger
+ self.LOGFD = sl
# Initialize our variables
self.separator = self.SEP
@@ -139,7 +144,13 @@ class Cyrus(cyruslib.CYRUS):
Login to the Cyrus IMAP server through cyruslib.CYRUS, but set our
hierarchy separator.
"""
- cyruslib.CYRUS.login(self, *args, **kw)
+ try:
+ cyruslib.CYRUS.login(self, *args, **kw)
+ except cyruslib.CYRUSError, errmsg:
+ log.error("Login to Cyrus IMAP server failed: %r", errmsg)
+ except Exception, errmsg:
+ log.exception(errmsg)
+
self.separator = self.SEP
try:
self._id()
diff --git a/pykolab/itip/__init__.py b/pykolab/itip/__init__.py
index f08b32b..0172c09 100644
--- a/pykolab/itip/__init__.py
+++ b/pykolab/itip/__init__.py
@@ -50,7 +50,7 @@ def objects_from_message(message, objnames, methods=None):
# Get the itip_payload
itip_payload = part.get_payload(decode=True)
- log.debug(_("Raw iTip payload (%r): %r") % (part.get_param('charset'), itip_payload), level=9)
+ log.debug(_("Raw iTip payload (%r): %r") % (part.get_param('charset'), itip_payload), level=8)
# Convert unsupported timezones, etc.
itip_payload = _convert_itip_payload(itip_payload)
@@ -71,7 +71,7 @@ def objects_from_message(message, objnames, methods=None):
itip = {}
if c['uid'] in seen_uids:
- log.debug(_("Duplicate iTip object: %s") % (c['uid']), level=9)
+ log.debug(_("Duplicate iTip object: %s") % (c['uid']), level=8)
continue
# From the event, take the following properties:
diff --git a/pykolab/logger.py b/pykolab/logger.py
index 3ad16e9..481c270 100644
--- a/pykolab/logger.py
+++ b/pykolab/logger.py
@@ -27,6 +27,31 @@ import time
from pykolab.translate import _
+class StderrToLogger(object):
+ """
+ Fake file-like stream object that redirects writes to a logger instance.
+ """
+ def __init__(self, logger, log_level=logging.DEBUG):
+ self.logger = logger
+ self.log_level = log_level
+ self.linebuf = ''
+
+ def write(self, buf):
+ # ugly patch to make smtplib debug logging records appear on one line in log file
+ # smtplib uses "print>>stderr, var, var" statements for debug logging. These
+ # statements are splited into separate lines on separating whitespace.
+ for line in buf.rstrip().splitlines():
+ if buf != '\n':
+ if line.startswith('send:') or line.startswith('reply:'):
+ self.linebuf = line
+ return
+ else:
+ self.logger.log(self.log_level, '%s %s', self.linebuf, line.rstrip()[:150])
+ self.linebuf = ''
+
+ def flush(self):
+ pass
+
class Logger(logging.Logger):
"""
The PyKolab version of a logger.
@@ -98,7 +123,7 @@ class Logger(logging.Logger):
logging.Logger.__init__(self, name)
- plaintextformatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s")
+ plaintextformatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s [%(process)d] %(message)s")
if not self.fork:
self.console_stdout = logging.StreamHandler(sys.stdout)
@@ -213,7 +238,6 @@ class Logger(logging.Logger):
if level <= self.debuglevel:
# TODO: Not the way it's supposed to work!
- self.log(logging.DEBUG, '[%d]: %s' % (os.getpid(),msg))
-
+ self.log(logging.DEBUG, msg)
logging.setLoggerClass(Logger)
diff --git a/pykolab/plugins/roundcubedb/__init__.py b/pykolab/plugins/roundcubedb/__init__.py
index a7f289e..40271c3 100644
--- a/pykolab/plugins/roundcubedb/__init__.py
+++ b/pykolab/plugins/roundcubedb/__init__.py
@@ -45,7 +45,7 @@ class KolabRoundcubedb(object):
domain - domain name
"""
- log.debug(_("user_delete: %r") % (kw), level=9)
+ log.debug(_("user_delete: %r") % (kw), level=8)
if os.path.isdir('/usr/share/roundcubemail'):
rcpath = '/usr/share/roundcubemail/'
@@ -64,6 +64,6 @@ class KolabRoundcubedb(object):
if proc.returncode != 0:
log.error(rcpath + "bin/deluser.sh exited with error %d: %r" % (proc.returncode, procerr))
else:
- log.debug(rcpath + "bin/deluser.sh success: %r; %r" % (procout, procerr), level=9)
+ log.debug(rcpath + "bin/deluser.sh success: %r; %r" % (procout, procerr), level=8)
return None