summaryrefslogtreecommitdiffstats
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
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
-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
-rw-r--r--wallace/module_invitationpolicy.py60
-rw-r--r--wallace/module_resources.py46
-rw-r--r--wallace/modules.py50
10 files changed, 135 insertions, 114 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
diff --git a/wallace/module_invitationpolicy.py b/wallace/module_invitationpolicy.py
index fac1fe7..17dc71c 100644
--- a/wallace/module_invitationpolicy.py
+++ b/wallace/module_invitationpolicy.py
@@ -184,7 +184,7 @@ def description():
def cleanup():
global auth, imap, write_locks
- log.debug("cleanup(): %r, %r" % (auth, imap), level=9)
+ log.debug("cleanup(): %r, %r" % (auth, imap), level=8)
auth.disconnect()
del auth
@@ -210,7 +210,7 @@ def execute(*args, **kw):
if not os.path.isdir(os.path.join(mybasepath, stage)):
os.makedirs(os.path.join(mybasepath, stage))
- log.debug(_("Invitation policy called for %r, %r") % (args, kw), level=9)
+ log.debug(_("Invitation policy called for %r, %r") % (args, kw), level=8)
auth = Auth()
imap = IMAP()
@@ -280,7 +280,7 @@ def execute(*args, **kw):
else:
any_itips = True
- log.debug(_("iTip objects attached to this message contain the following information: %r") % (itip_events), level=9)
+ log.debug(_("iTip objects attached to this message contain the following information: %r") % (itip_events), level=8)
# See if any iTip actually allocates a user.
if any_itips and len([x['uid'] for x in itip_events if x.has_key('attendees') or x.has_key('organizer')]) > 0:
@@ -399,7 +399,7 @@ def process_itip_request(itip_event, policy, recipient_email, sender_email, rece
try:
receiving_attendee = itip_event['xml'].get_attendee_by_email(recipient_email)
- log.debug(_("Receiving Attendee: %r") % (receiving_attendee), level=9)
+ log.debug(_("Receiving Attendee: %r") % (receiving_attendee), level=8)
except Exception, errmsg:
log.error("Could not find envelope attendee: %r" % (errmsg))
return MESSAGE_FORWARD
@@ -528,7 +528,7 @@ def process_itip_reply(itip_event, policy, recipient_email, sender_email, receiv
if policy & ACT_UPDATE:
try:
sender_attendee = itip_event['xml'].get_attendee_by_email(sender_email)
- log.debug(_("Sender Attendee: %r") % (sender_attendee), level=9)
+ log.debug(_("Sender Attendee: %r") % (sender_attendee), level=8)
except Exception, errmsg:
log.error("Could not find envelope sender attendee: %r" % (errmsg))
return MESSAGE_FORWARD
@@ -573,17 +573,17 @@ def process_itip_reply(itip_event, policy, recipient_email, sender_email, receiv
if not existing_delegatee:
existing.add_attendee(sender_delegatee)
- log.debug(_("Add delegatee: %r") % (sender_delegatee.to_dict()), level=9)
+ log.debug(_("Add delegatee: %r") % (sender_delegatee.to_dict()), level=8)
else:
existing_delegatee.copy_from(sender_delegatee)
- log.debug(_("Update existing delegatee: %r") % (existing_delegatee.to_dict()), level=9)
+ log.debug(_("Update existing delegatee: %r") % (existing_delegatee.to_dict()), level=8)
updated_attendees.append(sender_delegatee)
# copy all parameters from replying attendee (e.g. delegated-to, role, etc.)
existing_attendee.copy_from(sender_attendee)
existing.update_attendees([existing_attendee])
- log.debug(_("Update delegator: %r") % (existing_attendee.to_dict()), level=9)
+ log.debug(_("Update delegator: %r") % (existing_attendee.to_dict()), level=8)
except Exception, errmsg:
log.error("Could not find delegated-to attendee: %r" % (errmsg))
@@ -699,7 +699,7 @@ def user_dn_from_email_address(email_address):
if isinstance(user_dn, basestring):
log.debug(_("User DN: %r") % (user_dn), level=8)
else:
- log.debug(_("No user record(s) found for %r") % (email_address), level=9)
+ log.debug(_("No user record(s) found for %r") % (email_address), level=8)
# remember this lookup
user_dn_from_email_address.cache[email_address] = user_dn
@@ -978,7 +978,7 @@ def check_availability(itip_event, receiving_user):
break
end = time.time()
- log.debug(_("start: %r, end: %r, total: %r, messages: %d") % (start, end, (end-start), num_messages), level=9)
+ log.debug(_("start: %r, end: %r, total: %r, messages: %d") % (start, end, (end-start), num_messages), level=8)
# remember the result of this check for further iterations
itip_event['_conflicts'] = conflict
@@ -1006,7 +1006,7 @@ def set_write_lock(key, wait=True):
if not wait:
return False
- log.debug(_("%r is locked, waiting...") % (key), level=9)
+ log.debug(_("%r is locked, waiting...") % (key), level=8)
time.sleep(0.5)
locktime = os.path.getmtime(filename) if os.path.isfile(filename) else 0
@@ -1284,28 +1284,8 @@ def send_update_notification(object, receiving_user, old=None, reply=True, sende
msg['From'] = Header(utils.str2unicode('%s' % orgname) if orgname else '')
msg['From'].append("<%s>" % orgemail)
- smtp = smtplib.SMTP("localhost", 10027)
-
- if conf.debuglevel > 8:
- smtp.set_debuglevel(True)
-
- success = False
- retries = 5
-
- while not success and retries > 0:
- try:
- success = smtp.sendmail(orgemail, receiving_user['mail'], msg.as_string())
- log.debug(_("Sent update notification to %r: %r") % (receiving_user['mail'], success), level=8)
- smtp.quit()
- break
- except Exception, errmsg:
- log.error(_("SMTP sendmail error: %r") % (errmsg))
-
- time.sleep(10)
- retries -= 1
-
- return success
-
+ modules._sendmail(orgemail, receiving_user['mail'], msg.as_string())
+ log.debug(_("Sent update notification to %r: %r") % (receiving_user['mail'], success), level=8)
def send_cancel_notification(object, receiving_user, deleted=False, sender=None, comment=None):
"""
@@ -1366,18 +1346,8 @@ def send_cancel_notification(object, receiving_user, deleted=False, sender=None,
msg['From'] = Header(utils.str2unicode('%s' % orgname) if orgname else '')
msg['From'].append("<%s>" % orgemail)
- smtp = smtplib.SMTP("localhost", 10027)
-
- if conf.debuglevel > 8:
- smtp.set_debuglevel(True)
-
- try:
- smtp.sendmail(orgemail, receiving_user['mail'], msg.as_string())
- except Exception, errmsg:
- log.error(_("SMTP sendmail error: %r") % (errmsg))
-
- smtp.quit()
-
+ modules._sendmail(orgemail, receiving_user['mail'], msg.as_string())
+ log.debug(_("Sent cancel notification to %r: %r") % (receiving_user['mail'], success), level=8)
def is_auto_reply(user, sender_email, type):
accept_available = False
diff --git a/wallace/module_resources.py b/wallace/module_resources.py
index ed2baf8..c216276 100644
--- a/wallace/module_resources.py
+++ b/wallace/module_resources.py
@@ -94,7 +94,7 @@ def description():
def cleanup():
global auth, imap
- log.debug("cleanup(): %r, %r" % (auth, imap), level=9)
+ log.debug("cleanup(): %r, %r" % (auth, imap), level=8)
auth.disconnect()
del auth
@@ -196,7 +196,7 @@ def execute(*args, **kw):
log.debug(
_("iTip events attached to this message contain the " + \
"following information: %r") % (itip_events),
- level=9
+ level=8
)
if any_itips:
@@ -275,7 +275,7 @@ def execute(*args, **kw):
try:
sender_attendee = itip_event['xml'].get_attendee_by_email(sender_email)
owner_reply = sender_attendee.get_participant_status()
- log.debug(_("Sender Attendee: %r => %r") % (sender_attendee, owner_reply), level=9)
+ log.debug(_("Sender Attendee: %r => %r") % (sender_attendee, owner_reply), level=8)
except Exception, e:
log.error(_("Could not find envelope sender attendee: %r") % (e))
continue
@@ -317,7 +317,7 @@ def execute(*args, **kw):
try:
receiving_attendee = itip_event['xml'].get_attendee_by_email(receiving_resource['mail'])
- log.debug(_("Receiving Resource: %r; %r") % (receiving_resource, receiving_attendee), level=9)
+ log.debug(_("Receiving Resource: %r; %r") % (receiving_resource, receiving_attendee), level=8)
except Exception, e:
log.error(_("Could not find envelope attendee: %r") % (e))
continue
@@ -395,7 +395,7 @@ def execute(*args, **kw):
# Look for ACT_REJECT policy
if resource is not None:
invitationpolicy = get_resource_invitationpolicy(resource)
- log.debug(_("Apply invitation policies %r") % (invitationpolicy), level=9)
+ log.debug(_("Apply invitation policies %r") % (invitationpolicy), level=8)
if invitationpolicy is not None:
for policy in invitationpolicy:
@@ -488,7 +488,7 @@ def expunge_resource_calendar(mailbox):
for num in data[0].split():
log.debug(
_("Fetching message ID %r from folder %r") % (num, mailbox),
- level=9
+ level=8
)
typ, data = imap.imap.m.fetch(num, '(RFC822)')
@@ -542,20 +542,20 @@ def check_availability(itip_events, resource_dns, resources, receiving_attendee=
end = time.time()
- log.debug(_("start: %r, end: %r, total: %r, messages: %d") % (start, end, (end-start), num_messages), level=9)
+ log.debug(_("start: %r, end: %r, total: %r, messages: %d") % (start, end, (end-start), num_messages), level=8)
# For each resource (collections are first!)
# check conflicts and either accept or decline the reservation request
for resource in resource_dns:
- log.debug(_("Polling for resource %r") % (resource), level=9)
+ log.debug(_("Polling for resource %r") % (resource), level=8)
if not resources.has_key(resource):
- log.debug(_("Resource %r has been popped from the list") % (resource), level=9)
+ log.debug(_("Resource %r has been popped from the list") % (resource), level=8)
continue
if not resources[resource].has_key('conflicting_events'):
- log.debug(_("Resource is a collection"), level=9)
+ log.debug(_("Resource is a collection"), level=8)
# check if there are non-conflicting collection members
conflicting_members = [x for x in resources[resource]['uniquemember'] if resources[x]['conflict']]
@@ -568,7 +568,7 @@ def check_availability(itip_events, resource_dns, resources, receiving_attendee=
log.debug(_("Removed conflicting resources from %r: (%r) => %r") % (
resource, conflicting_members, resources[resource]['uniquemember']
- ), level=9)
+ ), level=8)
else:
# TODO: shuffle existing bookings of collection members in order
@@ -578,7 +578,7 @@ def check_availability(itip_events, resource_dns, resources, receiving_attendee=
continue
if len(resources[resource]['conflicting_events']) > 0:
- log.debug(_("Conflicting events: %r for resource %r") % (resources[resource]['conflicting_events'], resource), level=9)
+ log.debug(_("Conflicting events: %r for resource %r") % (resources[resource]['conflicting_events'], resource), level=8)
done = False
@@ -664,7 +664,7 @@ def read_resource_calendar(resource_rec, itip_events):
log.debug(
_("Checking events in resource folder %r") % (mailbox),
- level=9
+ level=8
)
# set read ACLs for admin user
@@ -683,7 +683,7 @@ def read_resource_calendar(resource_rec, itip_events):
log.debug(
_("Fetching message UID %r from folder %r") % (num, mailbox),
- level=9
+ level=8
)
typ, data = imap.imap.m.fetch(num, '(UID RFC822)')
@@ -737,7 +737,7 @@ def find_existing_event(uid, recurrence_id, resource_rec):
master = None
mailbox = resource_rec['kolabtargetfolder']
- log.debug(_("Searching %r for event %r") % (mailbox, uid), level=9)
+ log.debug(_("Searching %r for event %r") % (mailbox, uid), level=8)
try:
imap.imap.m.select(imap.folder_quote(mailbox))
@@ -802,7 +802,7 @@ def accept_reservation_request(itip_event, resource, delegator=None, confirmed=F
if not confirmed and owner:
if invitationpolicy is None:
invitationpolicy = get_resource_invitationpolicy(resource)
- log.debug(_("Apply invitation policies %r") % (invitationpolicy), level=9)
+ log.debug(_("Apply invitation policies %r") % (invitationpolicy), level=8)
if invitationpolicy is not None:
for policy in invitationpolicy:
@@ -934,7 +934,7 @@ def delete_resource_event(uid, resource, msguid=None):
log.debug(_("Delete resource calendar object %r in %r: %r") % (
uid, resource['kolabtargetfolder'], data
- ), level=9)
+ ), level=8)
for num in data[0].split():
imap.imap.m.store(num, '+FLAGS', '\\Deleted')
@@ -993,7 +993,7 @@ def resource_record_from_email_address(email_address):
if len(resource_records) > 0:
log.debug(_("Resource record(s): %r") % (resource_records), level=8)
else:
- log.debug(_("No resource (collection) records found for %r") % (email_address), level=9)
+ log.debug(_("No resource (collection) records found for %r") % (email_address), level=8)
elif isinstance(resource_records, basestring):
resource_records = [ resource_records ]
@@ -1015,7 +1015,7 @@ def resource_records_from_itip_events(itip_events, recipient_email=None):
resource_records = []
- log.debug(_("Raw itip_events: %r") % (itip_events), level=9)
+ log.debug(_("Raw itip_events: %r") % (itip_events), level=8)
attendees_raw = []
for list_attendees_raw in [x for x in [y['attendees'] for y in itip_events if y.has_key('attendees') and isinstance(y['attendees'], list)]]:
attendees_raw.extend(list_attendees_raw)
@@ -1023,7 +1023,7 @@ def resource_records_from_itip_events(itip_events, recipient_email=None):
for list_attendees_raw in [y['attendees'] for y in itip_events if y.has_key('attendees') and isinstance(y['attendees'], basestring)]:
attendees_raw.append(list_attendees_raw)
- log.debug(_("Raw set of attendees: %r") % (attendees_raw), level=9)
+ log.debug(_("Raw set of attendees: %r") % (attendees_raw), level=8)
# TODO: Resources are actually not implemented in the format. We reset this
# list later.
@@ -1031,7 +1031,7 @@ def resource_records_from_itip_events(itip_events, recipient_email=None):
for list_resources_raw in [x for x in [y['resources'] for y in itip_events if y.has_key('resources')]]:
resources_raw.extend(list_resources_raw)
- log.debug(_("Raw set of resources: %r") % (resources_raw), level=9)
+ log.debug(_("Raw set of resources: %r") % (resources_raw), level=8)
# consider organizer (in REPLY messages), too
organizers_raw = [re.sub('\+[A-Za-z0-9=/-]+@', '@', str(y['organizer'])) for y in itip_events if y.has_key('organizer')]
@@ -1065,7 +1065,7 @@ def resource_records_from_itip_events(itip_events, recipient_email=None):
resource_records.extend(_resource_records)
log.debug(_("Resource record(s): %r") % (_resource_records), level=8)
else:
- log.debug(_("No resource (collection) records found for %r") % (attendee), level=9)
+ log.debug(_("No resource (collection) records found for %r") % (attendee), level=8)
elif isinstance(_resource_records, basestring):
resource_records.append(_resource_records)
@@ -1236,7 +1236,7 @@ def get_resource_invitationpolicy(resource):
if not isinstance(collections, list):
collections = [ (collections['dn'],collections) ]
- log.debug(_("Check collections %r for kolabinvitationpolicy attributes") % (collections), level=9)
+ log.debug(_("Check collections %r for kolabinvitationpolicy attributes") % (collections), level=8)
for dn,collection in collections:
# ldap.search_entry_by_attribute() doesn't return the attributes lower-cased
diff --git a/wallace/modules.py b/wallace/modules.py
index 44bb1e0..1d25b1c 100644
--- a/wallace/modules.py
+++ b/wallace/modules.py
@@ -20,7 +20,6 @@
import os
import sys
import time
-import traceback
from email import message_from_string
from email.message import Message
@@ -117,8 +116,7 @@ def execute(name, *args, **kw):
try:
return modules[name]['function'](*args, **kw)
except Exception, errmsg:
- log.error(_("Unknown error occurred; %r") % (errmsg))
- log.error("%s" % (traceback.format_exc()))
+ log.exception(_("Module %r - Unknown error occurred; %r") % (name, errmsg))
def heartbeat(name, *args, **kw):
if not modules.has_key(name):
@@ -130,27 +128,40 @@ def heartbeat(name, *args, **kw):
def _sendmail(sender, recipients, msg):
# NOTE: Use "127.0.0.1" here for IPv6 (see also the service
# definition in master.cf).
- smtp = smtplib.SMTP("127.0.0.1", 10027)
+
+ sl = pykolab.logger.StderrToLogger(log)
+ smtplib.stderr = sl
+
+ smtp = smtplib.SMTP(timeout=5)
if conf.debuglevel > 8:
- smtp.set_debuglevel(True)
+ smtp.set_debuglevel(1)
+
+ success = False
+ retries = 5
- # Not an infinite loop
- while True:
+ while not success and retries > 0:
try:
- smtp.sendmail(
- sender,
- recipients,
- msg
- )
+ log.debug(_("Trying to send email via smtplib from %r, to %r") % (sender, recipients), level=8)
+ smtp.connect("127.0.0.1", 10027)
+ _response = smtp.sendmail(sender, recipients, msg)
+
+ if len(_response) == 0:
+ log.debug(_("SMTP sendmail OK"), level=8)
+ else:
+ log.debug(_("SMTP sendmail returned: %r") % (_response), level=8)
smtp.quit()
- return True
+ success = True
+ break
except smtplib.SMTPServerDisconnected, errmsg:
- smtp.quit()
- smtp.connect()
+ log.error("SMTP Server Disconnected Error, %r" % (errmsg))
+
+ except smtplib.SMTPConnectError, errmsg:
+ # DEFER
+ log.error("SMTP Connect Error, %r" % (errmsg))
except smtplib.SMTPDataError, errmsg:
# DEFER
@@ -169,10 +180,13 @@ def _sendmail(sender, recipients, msg):
log.error("SMTP Sender Refused, %r" % (errmsg))
except Exception, errmsg:
- log.error(_("Unknown error occurred; %r") % (errmsg))
- log.error("%r" % (traceback.format_exc()))
+ log.exception(_("smtplib - Unknown error occurred: %r") % (errmsg))
+
+ smtp.quit()
+ time.sleep(10)
+ retries -= 1
- return False
+ return success
def cb_action_HOLD(module, filepath):
log.info(_("Holding message in queue for manual review (%s by %s)") % (filepath, module))