From 0beba139ed8cd6d421df375ef5feb4cd6a07e24c Mon Sep 17 00:00:00 2001 From: Patrick Ulbrich Date: Sat, 10 Aug 2013 14:39:29 +0200 Subject: [PATCH] logging and config dir related fixes replaced stdout redirection by propper logging only create the config dir when it is actually needed --- Mailnag/common/accounts.py | 5 ++-- Mailnag/common/keyring.py | 6 ++-- Mailnag/common/plugins.py | 5 ++-- Mailnag/common/utils.py | 9 +++--- Mailnag/daemon/idlers.py | 17 ++++++----- Mailnag/daemon/mailchecker.py | 12 +++----- Mailnag/daemon/mails.py | 49 +++++++++++++++--------------- Mailnag/mailnag.py | 54 ++++++++++++++++++++++++---------- Mailnag/plugins/soundplugin.py | 2 +- mailnagd | 7 +---- 10 files changed, 91 insertions(+), 75 deletions(-) diff --git a/Mailnag/common/accounts.py b/Mailnag/common/accounts.py index 7be8b38..74039f1 100644 --- a/Mailnag/common/accounts.py +++ b/Mailnag/common/accounts.py @@ -23,6 +23,7 @@ # import poplib +import logging import daemon.imaplib2 as imaplib from common.i18n import _ from common.keyring import Keyring @@ -95,7 +96,7 @@ class Account: self._conn = conn except: - print "Error: Cannot connect to IMAP account: %s. " % self.server + logging.error("Cannot connect to IMAP account '%s'." % self.server) try: if conn != None: # conn.close() # allowed in SELECTED state only @@ -131,7 +132,7 @@ class Account: self._conn = conn except: - print "Error: Cannot connect to POP account: %s. " % self.server + logging.error("Cannot connect to POP account: '%s'." % self.server) try: if conn != None: conn.quit() diff --git a/Mailnag/common/keyring.py b/Mailnag/common/keyring.py index 0c9aaa1..17e7ebf 100644 --- a/Mailnag/common/keyring.py +++ b/Mailnag/common/keyring.py @@ -59,15 +59,15 @@ class Keyring: if item.get_secret() != '': return item.get_secret() else: - # DEBUG print "Keyring.get(): No Keyring Password for %s://%s@%s." % (protocol, user, server) + # logging.debug("Keyring.get(): No Keyring Password for %s://%s@%s." % (protocol, user, server)) return '' else: - # DEBUG print "Keyring.get(): %s://%s@%s not in Keyring." % (protocol, user, server) + # logging.debug("Keyring.get(): %s://%s@%s not in Keyring." % (protocol, user, server)) return '' else: - # DEBUG print "Keyring.get(): Neither default- nor 'login'-Keyring available." + # logging.debug("Keyring.get(): Neither default- nor 'login'-Keyring available.") return '' diff --git a/Mailnag/common/plugins.py b/Mailnag/common/plugins.py index 6697d7a..1c7d28e 100644 --- a/Mailnag/common/plugins.py +++ b/Mailnag/common/plugins.py @@ -24,6 +24,7 @@ import os import imp import inspect +import logging from common.config import cfg_folder @@ -242,7 +243,7 @@ class Plugin: p.init(modname, cfg, mailnag_controller) plugins.append(p) except: - print "Failed to instantiate plugin '%s'" % modname + logging.exception("Failed to instantiate plugin '%s'" % modname) return plugins @@ -275,6 +276,6 @@ class Plugin: plugin_types.append((modname, t)) except: - print "Error while opening plugin file '%s'" % f + logging.exception("Error while opening plugin file '%s'" % f) return plugin_types diff --git a/Mailnag/common/utils.py b/Mailnag/common/utils.py index 64cc976..d334f57 100644 --- a/Mailnag/common/utils.py +++ b/Mailnag/common/utils.py @@ -24,12 +24,12 @@ import xdg.BaseDirectory as base import os -import sys import time import dbus import urllib2 import subprocess import threading +import logging from common.dist_cfg import PACKAGE_NAME, DBUS_BUS_NAME, DBUS_OBJ_PATH @@ -71,8 +71,7 @@ def shutdown_existing_instance(): bus = dbus.SessionBus() if bus.name_has_owner(DBUS_BUS_NAME): - sys.stdout.write('Shutting down existing Mailnag process...') - sys.stdout.flush() + logging.info('Shutting down existing Mailnag process...') try: proxy = bus.get_object(DBUS_BUS_NAME, DBUS_OBJ_PATH) @@ -83,9 +82,9 @@ def shutdown_existing_instance(): while bus.name_has_owner(DBUS_BUS_NAME): time.sleep(2) - sys.stdout.write('OK\n') + logging.info('Mailnag has been shut down successfully.') except: - sys.stdout.write('FAILED\n') + logging.error('Failed to shut down Mailnag.') def start_subprocess(args, shell = False, callback = None): diff --git a/Mailnag/daemon/idlers.py b/Mailnag/daemon/idlers.py index c613acf..dd49ff2 100644 --- a/Mailnag/daemon/idlers.py +++ b/Mailnag/daemon/idlers.py @@ -24,7 +24,7 @@ import threading import time -import sys +import logging from daemon.imaplib2 import AUTH @@ -74,7 +74,7 @@ class Idler(object): pass self._disposed = True - print "Idler closed" + logging.info('Idler closed') # idle thread @@ -119,7 +119,7 @@ class Idler(object): def _reconnect(self): # connection has been reset by provider -> try to reconnect - print "Idler thread for account '%s' has been disconnected" % self._account.name + logging.info("Idler thread for account '%s' has been disconnected" % self._account.name) # conn has already been closed, don't try to close it again # self._conn.close() # (calls idle_callback) @@ -129,14 +129,15 @@ class Idler(object): self._conn = None while (self._conn == None) and (not self._event.isSet()): - sys.stdout.write("Trying to reconnect Idler thread for account '%s'..." % self._account.name) + logging.info("Trying to reconnect Idler thread for account '%s'." % self._account.name) self._conn = self._account.get_connection(use_existing = False) if self._conn == None: - sys.stdout.write("FAILED\n") - print "Trying again in %s minutes" % self.RECONNECT_RETRY_INTERVAL + logging.error("Failed to reconnect Idler thread for account '%s'." % self._account.name) + lgging.info("Trying to reconnect Idler thread for account '%s' in %s minutes", + (self._account.name , self.RECONNECT_RETRY_INTERVAL)) self._wait(60 * self.RECONNECT_RETRY_INTERVAL) # don't hammer the server else: - sys.stdout.write("OK\n") + logging.error("Successfully reconnected Idler thread for account '%s'." % self._account.name) if self._conn != None: self._select(self._conn, self._account.folder) @@ -174,7 +175,7 @@ class IdlerRunner: idler.run() self._idlerlist.append(idler) except Exception as ex: - print "Error: Failed to create an idler thread for account '%s'" % acc.name + logging.error("Error: Failed to create an idler thread for account '%s'" % acc.name) def dispose(self): diff --git a/Mailnag/daemon/mailchecker.py b/Mailnag/daemon/mailchecker.py index 79d31ff..0d0b0e6 100644 --- a/Mailnag/daemon/mailchecker.py +++ b/Mailnag/daemon/mailchecker.py @@ -23,9 +23,8 @@ # import threading -import sys +import logging import time -import traceback from common.utils import is_online from common.i18n import _ @@ -37,7 +36,7 @@ def try_call(f, err_retval = None): try: return f() except: - traceback.print_exc() + logging.exception('Caught an exception.') return err_retval @@ -56,13 +55,13 @@ class MailChecker: # make sure multiple threads (idler and polling thread) # don't check for mails simultaneously. with self._mailcheck_lock: - print 'Checking %s email account(s) at: %s' % (len(accounts), time.asctime()) + logging.info('Checking %s email account(s) at: %s.' % (len(accounts), time.asctime())) for f in self._hookreg.get_hook_funcs(HookTypes.MAIL_CHECK): try_call( f ) if not is_online(): - print 'Error: No internet connection' + logging.error('No internet connection.') return all_mails = self._mailsyncer.sync(accounts) @@ -97,9 +96,6 @@ class MailChecker: try_call( lambda: f(filtered_new_mails, filtered_unseen_mails) ) self._reminder.save(all_mails) - - # write stdout to log file - sys.stdout.flush() self._firstcheck = False return diff --git a/Mailnag/daemon/mails.py b/Mailnag/daemon/mails.py index 5bead3d..4ee3076 100644 --- a/Mailnag/daemon/mails.py +++ b/Mailnag/daemon/mails.py @@ -24,9 +24,9 @@ # import time -import sys import email import os +import logging from common.i18n import _ from common.config import cfg_folder @@ -80,16 +80,16 @@ class MailCollector: try: status, data = srv.search(None, 'UNSEEN') # ALL or UNSEEN except: - print "The folder:", folder, "does not exist, using INBOX instead" + logging.warning('The folder: %s does not exist, using INBOX instead.', folder) try: # if search fails select INBOX and try again srv.select('INBOX', readonly=True) status, data = srv.search(None, 'UNSEEN') # ALL or UNSEEN except: - print "INBOX Could not be found", sys.exc_info()[0] + logging.warning("INBOX couldn't be found.") if status != 'OK' or None in [d for d in data]: - print "Folder", folder, "in status", status, "| Data:", data, "\n" + logging.debug('Folder %s in status %s | Data: %s', (folder, status, data)) continue # Bugfix LP-735071 for num in data[0].split(): typ, msg_data = srv.fetch(num, '(BODY.PEEK[HEADER])') # header only (without setting READ flag) @@ -98,27 +98,27 @@ class MailCollector: try: msg = email.message_from_string(response_part[1]) except: - print "Could not get IMAP message." # debug + logging.debug("Couldn't get IMAP message.") continue try: try: # get sender and format it sender = self._format_header('sender', msg['From']) except KeyError: - print "KeyError exception for key 'From' in message." # debug + logging.debug("Caught KeyError exception for key 'From' in message.") sender = self._format_header('sender', msg['from']) except: - print "Could not get sender from IMAP message." # debug + logging.debug("Couldn't get sender from IMAP message.") sender = ('', '') try: try: # get date and format it datetime = self._format_header('date', msg['Date']) except KeyError: - print "KeyError exception for key 'Date' in message." # debug + logging.debug("Caught KeyError exception for key 'Date' in message.") datetime = self._format_header('date', msg['date']) except: - print "Could not get date from IMAP message." # debug + logging.debug("Couldn't get date from IMAP message.") # current time to seconds datetime = int(time.time()) try: @@ -126,15 +126,15 @@ class MailCollector: # get subject and format it subject = self._format_header('subject', msg['Subject']) except KeyError: - print "KeyError exception for key 'Subject' in message." # debug + logging.debug("Caught KeyError exception for key 'Subject' in message.") subject = self._format_header('subject', msg['subject']) except: - print "Could not get subject from IMAP message." # debug + logging.debug("Couldn't get subject from IMAP message.") subject = _('No subject') try: id = msg['Message-Id'] except: - print "Could not get id from IMAP message." # debug + logging.debug("Couldn't get id from IMAP message.") id = None if id == None or id == '': @@ -159,7 +159,7 @@ class MailCollector: # header plus first 0 lines from body message = srv.top(i, 0)[1] except: - print "Could not get POP message." # debug + logging.debug("Couldn't get POP message.") continue # convert list to string @@ -169,27 +169,27 @@ class MailCollector: # put message into email object and make a dictionary msg = dict(email.message_from_string(message_string)) except: - print "Could not get msg from POP message." # debug + logging.debug("Couldn't get msg from POP message.") continue try: try: # get sender and format it sender = self._format_header('sender', msg['From']) except KeyError: - print "KeyError exception for key 'From' in message." # debug + logging.debug("Caught KeyError exception for key 'From' in message.") sender = self._format_header('sender', msg['from']) except: - print "Could not get sender from POP message." # debug + logging.debug("Couldn't get sender from POP message.") sender = ('', '') try: try: # get date and format it datetime = self._format_header('date', msg['Date']) except KeyError: - print "KeyError exception for key 'Date' in message." # debug + logging.debug("Caught KeyError exception for key 'Date' in message.") datetime = self._format_header('date', msg['date']) except: - print "Could not get date from POP message." # debug + logging.debug("Couldn't get date from POP message.") # current time to seconds datetime = int(time.time()) try: @@ -197,16 +197,16 @@ class MailCollector: # get subject and format it subject = self._format_header('subject', msg['Subject']) except KeyError: - print "KeyError exception for key 'Subject' in message." # debug + logging.debug("Caught KeyError exception for key 'Subject' in message.") subject = self._format_header('subject', msg['subject']) except: - print "Could not get subject from POP message." + logging.debug("Couldn't get subject from POP message.") subject = _('No subject') try: # get id uidl = srv.uidl(i) except: - print "Could not get id from POP message." # debug + logging.debug("Couldn't get id from POP message.") uidl = None if uidl == None or uidl == '': @@ -226,8 +226,6 @@ class MailCollector: if sort: mail_list = sort_mails(mail_list, sort_desc = True) - # write stdout to log file - sys.stdout.flush() return mail_list @@ -252,7 +250,7 @@ class MailCollector: # convert 10-tupel to seconds incl. timezone shift datetime = email.utils.mktime_tz(parsed_date) except: - print 'Error: cannot format date.' + logging.warning('Cannot format date. Using current time.') # current time to seconds datetime = int(time.time()) return datetime @@ -392,6 +390,9 @@ class Reminder(dict): # save mail ids to file def save(self, mail_list): + if not os.path.exists(cfg_folder): + os.makedirs(cfg_folder) + dat_file = os.path.join(cfg_folder, 'mailnag.dat') f = open(dat_file, 'w') # open for overwrite for m in mail_list: diff --git a/Mailnag/mailnag.py b/Mailnag/mailnag.py index 2a0a5d9..70b6b58 100644 --- a/Mailnag/mailnag.py +++ b/Mailnag/mailnag.py @@ -26,10 +26,10 @@ from gi.repository import GObject, GLib from dbus.mainloop.glib import DBusGMainLoop import threading +import logging import os import time import signal -import traceback from common.config import read_cfg, cfg_exists, cfg_folder from common.utils import set_procname, is_online, shutdown_existing_instance @@ -38,6 +38,10 @@ from common.plugins import Plugin, HookRegistry, MailnagController from daemon.mailchecker import MailChecker from daemon.idlers import IdlerRunner +LOG_FILE = 'mailnagd.log' +LOG_LEVEL = logging.DEBUG +LOG_FORMAT = '%(levelname)s: %(message)s' + mainloop = None idlrunner = None plugins = [] @@ -78,7 +82,7 @@ def read_config(): def wait_for_inet_connection(): if not is_online(): - print 'Waiting for internet connection...' + logging.info('Waiting for internet connection...') while not is_online(): time.sleep(5) @@ -89,12 +93,12 @@ def cleanup(): # clean up resources if (start_thread != None) and (start_thread.is_alive()): start_thread.join() - print "Starter thread exited successfully" + logging.info('Starter thread exited successfully.') if (poll_thread != None) and (poll_thread.is_alive()): poll_thread_stop.set() poll_thread.join() - print "Polling thread exited successfully" + logging.info('Polling thread exited successfully.') if idlrunner != None: idlrunner.dispose() @@ -113,14 +117,30 @@ def cleanup(): event.wait(10.0) if not event.is_set(): - print "Warning: cleanup takes too long. Enforcing termination." + logging.warning('Cleanup takes too long. Enforcing termination.') os._exit(os.EX_SOFTWARE) if threading.active_count() > 1: - print 'Warning: there are still active threads. Enforcing termination.' + logging.warning('There are still active threads. Enforcing termination.') os._exit(os.EX_SOFTWARE) +def init_logging(): + if not os.path.exists(cfg_folder): + os.makedirs(cfg_folder) + + logging.basicConfig( + filename = os.path.join(cfg_folder, LOG_FILE), + filemode = 'w', + format = LOG_FORMAT, + level = LOG_LEVEL) + + stdout_handler = logging.StreamHandler() + stdout_handler.setLevel(LOG_LEVEL) + stdout_handler.setFormatter(logging.Formatter(LOG_FORMAT)) + logging.getLogger('').addHandler(stdout_handler) + + def sigterm_handler(data): if mainloop != None: mainloop.quit() @@ -137,9 +157,9 @@ def load_plugins(cfg, hookreg): for p in plugins: try: p.enable() - print "Successfully enabled plugin '%s'" % p.get_modname() + logging.info("Successfully enabled plugin '%s'." % p.get_modname()) except: - print "Failed to enable plugin '%s'" % p.get_modname() + logging.error("Failed to enable plugin '%s'." % p.get_modname()) def unload_plugins(): @@ -151,10 +171,10 @@ def unload_plugins(): p.disable() except: err = True - print "Failed to disable plugin '%s'" % p.get_modname() + logging.error("Failed to disable plugin '%s'." % p.get_modname()) if not err: - print "Plugins disabled successfully" + logging.info('Plugins disabled successfully.') def main(): @@ -162,6 +182,8 @@ def main(): set_procname("mailnagd") + init_logging() + GObject.threads_init() DBusGMainLoop(set_as_default = True) GLib.unix_signal_add(GLib.PRIORITY_HIGH, signal.SIGTERM, @@ -175,7 +197,7 @@ def main(): cfg = read_config() if (cfg == None): - print 'Error: Cannot find configuration file. Please run mailnag_config first.' + logging.critical('Cannot find configuration file. Please run mailnag-config first.') exit(1) wait_for_inet_connection() @@ -193,7 +215,7 @@ def main(): except KeyboardInterrupt: pass # ctrl+c pressed finally: - print "Shutting down..." + logging.info('Shutting down...') cleanup() @@ -210,7 +232,7 @@ def start(cfg, hookreg): try: mailchecker.check(accounts) except: - traceback.print_exc() + logging.exception('Caught an exception.') idle_accounts = filter(lambda acc: acc.imap and acc.idle, accounts) non_idle_accounts = filter(lambda acc: (not acc.imap) or (acc.imap and not acc.idle), accounts) @@ -229,7 +251,7 @@ def start(cfg, hookreg): mailchecker.check(non_idle_accounts) except: - traceback.print_exc() + logging.exception('Caught an exception.') poll_thread = threading.Thread(target = poll_func) poll_thread.start() @@ -241,13 +263,13 @@ def start(cfg, hookreg): try: mailchecker.check([account]) except: - traceback.print_exc() + logging.exception('Caught an exception.') idlrunner = IdlerRunner(idle_accounts, sync_func) idlrunner.run() except: - traceback.print_exc() + logging.exception('Caught an exception.') mainloop.quit() diff --git a/Mailnag/plugins/soundplugin.py b/Mailnag/plugins/soundplugin.py index 3b2e883..3e69734 100644 --- a/Mailnag/plugins/soundplugin.py +++ b/Mailnag/plugins/soundplugin.py @@ -102,7 +102,7 @@ class _GstPlayThread(threading.Thread): def run(self): def on_eos(bus, msg): -# print "EOS" # debug +# loggin.debug('EOS') self.ply.set_state(Gst.State.NULL) return True diff --git a/mailnagd b/mailnagd index 8284a57..236e19f 100755 --- a/mailnagd +++ b/mailnagd @@ -1,11 +1,6 @@ #!/bin/bash LIB_DIR=./Mailnag -config_dir="${XDG_CONFIG_HOME:-$HOME/.config}/mailnag" - -mkdir --parents "$config_dir" -rm --force "$config_dir/mailnag.log" - cd $(dirname $(readlink -f $0)) -python2 $LIB_DIR/mailnag.py >> "$config_dir/mailnag.log" 2>&1 & +python2 $LIB_DIR/mailnag.py &