diff --git a/pykolab/auth/__init__.py b/pykolab/auth/__init__.py --- a/pykolab/auth/__init__.py +++ b/pykolab/auth/__init__.py @@ -86,7 +86,7 @@ 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 @@ 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 @@ log.debug( _("Using section %s and domain %s") % (section,domain), - level=9 + level=8 ) log.debug( @@ -129,7 +129,7 @@ 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 @@ 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 @@ 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 --- a/pykolab/auth/ldap/__init__.py +++ b/pykolab/auth/ldap/__init__.py @@ -458,6 +458,7 @@ 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 @@ 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 @@ ldap.SCOPE_BASE, attributes ), - level=9 + level=8 ) _search = self.ldap.search_ext( @@ -854,7 +855,7 @@ 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 @@ _("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 @@ _("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 @@ _("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 @@ ) 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 @@ current_ldap_quota, default_quota ), - level=9 + level=8 ) new_quota = conf.plugins.exec_hook("set_user_folder_quota", kw={ @@ -2637,7 +2638,7 @@ args, kw ), - level=9 + level=8 ) # Typical for Persistent Change Control EntryChangeNotification @@ -2718,7 +2719,7 @@ # # 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 @@ '/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 --- a/pykolab/cli/sieve/cmd_refresh.py +++ b/pykolab/cli/sieve/cmd_refresh.py @@ -356,7 +356,7 @@ 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 --- a/pykolab/imap/cyrus.py +++ b/pykolab/imap/cyrus.py @@ -90,6 +90,11 @@ 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 @@ 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 --- a/pykolab/itip/__init__.py +++ b/pykolab/itip/__init__.py @@ -50,7 +50,7 @@ # 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 @@ 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 --- a/pykolab/logger.py +++ b/pykolab/logger.py @@ -27,6 +27,31 @@ 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 @@ 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 @@ 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 --- a/pykolab/plugins/roundcubedb/__init__.py +++ b/pykolab/plugins/roundcubedb/__init__.py @@ -45,7 +45,7 @@ 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 @@ 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 --- a/wallace/module_invitationpolicy.py +++ b/wallace/module_invitationpolicy.py @@ -184,7 +184,7 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 - + log.debug(_("Sent update notification to %r: %r") % (receiving_user['mail'], success), level=8) + modules._sendmail(orgemail, receiving_user['mail'], msg.as_string()) def send_cancel_notification(object, receiving_user, deleted=False, sender=None, comment=None): """ @@ -1366,18 +1346,8 @@ 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() - + log.debug(_("Sent cancel notification to %r: %r") % (receiving_user['mail'], success), level=8) + modules._sendmail(orgemail, receiving_user['mail'], msg.as_string()) def is_auto_reply(user, sender_email, type): accept_available = False diff --git a/wallace/module_resources.py b/wallace/module_resources.py --- a/wallace/module_resources.py +++ b/wallace/module_resources.py @@ -94,7 +94,7 @@ 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 @@ 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 @@ 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 @@ 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 @@ # 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ log.debug( _("Checking events in resource folder %r") % (mailbox), - level=9 + level=8 ) # set read ACLs for admin user @@ -683,7 +683,7 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 --- 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 @@ 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,39 @@ def _sendmail(sender, recipients, msg): # NOTE: Use "127.0.0.1" here for IPv6 (see also the service # definition in master.cf). + + sl = pykolab.logger.StderrToLogger(log) + smtplib.stderr = sl + smtp = smtplib.SMTP("127.0.0.1", 10027) 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) + _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 +179,13 @@ 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))