summaryrefslogtreecommitdiffstats
path: root/wallace
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 /wallace
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 'wallace')
-rw-r--r--wallace/module_invitationpolicy.py60
-rw-r--r--wallace/module_resources.py46
-rw-r--r--wallace/modules.py50
3 files changed, 70 insertions, 86 deletions
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))