Huge plugin & event manager upgrades.

1. Removed unused modules
2. Re-use event handlers with identical callbacks and args.
3. Removed plugin exceptions in favour of assertions.
4. Remove useless raw_keycmd and raw_bind config vars.
5. Implemented and use `after` and `cleanup` plugin hooks (correctly)
6. EM & plugins now use the python logging module to output messages
7. Null config items are removed automatically
8. Simpler mode plugin
9. The init plugins function is called after the INSTANCE_START event
10. New optparse option to silence event echoing to stdout
11. Close instance socket on INSTANCE_EXIT before event handling
12. Caught signals are logged
13. Show times on the messages in the log file
14. Refactor bind pluin to use uzbl.bindlet directly.
15. Refactor keycmd plugin to use uzbl.keycmd directly.
16. Refactored on_event plugin to use uzbl.on_events dict over UZBLS dict
17. Refactor completion plugin to use uzbl.completion set object.
18. Modified progress plugin to use config vars instead of `@progress k = v`
19. mode_config now a defaultdict(dict) (I.e. this allows you to
    `uzbl.mode_config[mode][var] = value` without needing to check `mode`
    is in the `uzbl.mode_config` dict).
20. Removed all default mode config values.
21. Removed all `get_mode()` and `set_mode(..)` functions (and the like).
22. Setting the mode is now done via the config object directly (I.e.
    `uzbl.config['mode'] = 'insert'`).
23. Uses the on_set plugin to watch for 'mode' and 'default_mode' config
    changes.
24. Don't raise the useless NEW_ON_SET event, missing ON_SET connect.
25. Plugin and EventHandler aren't suited as dict objects.
26. Also using collections.defaultdict(list) for uzbl.handlers dict.
27. Plugin `on_set.py` allows you to attach handlers to config var changes
28. Config plugin reduced to one `uzbl.config` dict-like object.
29. Update export and connect calls in plugins.
30. The functions connect, connect_dict, export, export_dict, require,
    logging are exported directly to the plugin namespace.
31. Moved parse_msg into Uzbl class.
32. Generally improved comments.
33. UzblEventDaemon now an object.
34. Various variable, function & class renames.

1 files changed, 620 insertions, 505 deletions

diff --git a/examples/data/scripts/uzbl-event-manager b/examples/data/scripts/uzbl-event-manager
index 7fa4a09..75a1c13 100755
--- a/examples/data/scripts/uzbl-event-manager
+++ b/examples/data/scripts/uzbl-event-manager
@@ -1,7 +1,7 @@
 #!/usr/bin/env python
 
 # Event Manager for Uzbl
-# Copyright (c) 2009, Mason Larobina <mason.larobina@gmail.com>
+# Copyright (c) 2009-2010, Mason Larobina <mason.larobina@gmail.com>
 # Copyright (c) 2009, Dieter Plaetinck <dieter@plaetinck.be>
 #
 # This program is free software: you can redistribute it and/or modify
@@ -26,21 +26,23 @@ Event manager for uzbl written in python.
 
 '''
 
+import atexit
 import imp
+import logging
 import os
-import sys
-import re
 import socket
-import pprint
+import sys
 import time
-import atexit
-from select import select
-from signal import signal, SIGTERM
-from optparse import OptionParser
-from traceback import print_exc
+import weakref
+from collections import defaultdict
 from functools import partial
+from glob import glob
 from itertools import count
-
+from optparse import OptionParser
+from select import select
+from signal import signal, SIGTERM, SIGINT
+from socket import socket, AF_UNIX, SOCK_STREAM
+from traceback import format_exc
 
 def xdghome(key, default):
     '''Attempts to use the environ XDG_*_HOME paths if they exist otherwise
@@ -52,11 +54,6 @@ def xdghome(key, default):
 
     return os.path.join(os.environ['HOME'], default)
 
-
-# ============================================================================
-# ::: Default configuration section ::::::::::::::::::::::::::::::::::::::::::
-# ============================================================================
-
 # `make install` will put the correct value here for your system
 PREFIX = '/usr/local/'
 
@@ -64,120 +61,34 @@ PREFIX = '/usr/local/'
 DATA_DIR = os.path.join(xdghome('DATA', '.local/share/'), 'uzbl/')
 CACHE_DIR = os.path.join(xdghome('CACHE', '.cache/'), 'uzbl/')
 
-# Event manager config dictionary. This is not to be confused with the config
-# dict that tracks variables in the uzbl instance.
-CONFIG = {
-    'verbose':         False,
-    'daemon_mode':     True,
-    'auto_close':      False,
-
-    'plugins_load':    [],
-    'plugins_ignore':  [],
-
-    'plugin_dirs':     [os.path.join(DATA_DIR, 'plugins/'),
-        os.path.join(PREFIX, 'share/uzbl/examples/data/plugins/')],
-
-    'server_socket':   os.path.join(CACHE_DIR, 'event_daemon'),
-    'pid_file':        os.path.join(CACHE_DIR, 'event_daemon.pid'),
-}
-
-# ============================================================================
-# ::: End of configuration section :::::::::::::::::::::::::::::::::::::::::::
-# ============================================================================
-
-
 # Define some globals.
 SCRIPTNAME = os.path.basename(sys.argv[0])
-FINDSPACES = re.compile("\s+")
-
-
-class ArgumentError(Exception):
-    pass
-
-
-def echo(msg):
-    '''Prints only if the verbose flag has been set.'''
-
-    if CONFIG['verbose']:
-        sys.stdout.write("%s: %s\n" % (SCRIPTNAME, msg))
-
-
-def error(msg):
-    '''Prints error messages to stderr.'''
-
-    sys.stderr.write("%s: error: %s\n" % (SCRIPTNAME, msg))
-
-
-def find_plugins(plugin_dirs):
-    '''Find all event manager plugins in the plugin dirs and return a
-    dictionary of {'plugin-name.py': '/full/path/to/plugin-name.py', ...}'''
-
-    plugins = {}
-
-    for plugin_dir in plugin_dirs:
-        plugin_dir = os.path.realpath(os.path.expandvars(plugin_dir))
-        if not os.path.isdir(plugin_dir):
-            continue
-
-        for filename in os.listdir(plugin_dir):
-            if not filename.lower().endswith('.py'):
-                continue
-
-            path = os.path.join(plugin_dir, filename)
-            if not os.path.isfile(path):
-                continue
-
-            if filename not in plugins:
-                plugins[filename] = plugin_dir
-
-    return plugins
 
+def get_exc():
+    '''Format `format_exc` for logging.'''
+    return "\n%s" % format_exc().rstrip()
 
-def load_plugins(plugin_dirs, load=None, ignore=None):
-    '''Load event manager plugins found in the plugin_dirs.'''
+def expandpath(path):
+    '''Expand and realpath paths.'''
+    return os.path.realpath(os.path.expandvars(path))
 
-    load = [] if load is None else load
-    ignore = [] if ignore is None else ignore
-
-    # Find the plugins in the plugin_dirs.
-    found = find_plugins(plugin_dirs)
-
-    if load:
-        # Ignore anything not in the load list.
-        for plugin in found.keys():
-            if plugin not in load:
-                del found[plugin]
-
-    if ignore:
-        # Ignore anything in the ignore list.
-        for plugin in found.keys():
-            if plugin in ignore:
-                del found[plugin]
-
-    # Print plugin list to be loaded.
-    pprint.pprint(found)
-
-    loaded = {}
-    # Load all found plugins into the loaded dict.
-    for (filename, plugin_dir) in found.items():
-        name = filename[:-3]
-        info = imp.find_module(name, [plugin_dir])
-        plugin = imp.load_module(name, *info)
-        loaded[(plugin_dir, filename)] = plugin
-
-    return loaded
+def ascii(u):
+    '''Convert unicode strings into ascii for transmission over
+    ascii-only streams/sockets/devices.'''
+    return u.encode('utf-8')
 
 
 def daemonize():
     '''Daemonize the process using the Stevens' double-fork magic.'''
 
+    logger.info('entering daemon mode')
+
     try:
         if os.fork():
             os._exit(0)
 
     except OSError:
-        print_exc()
-        sys.stderr.write("fork #1 failed")
+        logger.critical(get_exc())
         sys.exit(1)
 
     os.chdir('/')
@@ -189,8 +100,7 @@ def daemonize():
             os._exit(0)
 
     except OSError:
-        print_exc()
-        sys.stderr.write("fork #2 failed")
+        logger.critical(get_exc())
         sys.exit(1)
 
     if sys.stdout.isatty():
@@ -206,6 +116,8 @@ def daemonize():
     os.dup2(stdout.fileno(), sys.stdout.fileno())
     os.dup2(stderr.fileno(), sys.stderr.fileno())
 
+    logger.info('entered daemon mode')
+
 
 def make_dirs(path):
     '''Make all basedirs recursively as required.'''
@@ -213,637 +125,840 @@ def make_dirs(path):
     try:
         dirname = os.path.dirname(path)
         if not os.path.isdir(dirname):
+            logger.debug('creating directories %r' % dirname)
             os.makedirs(dirname)
 
     except OSError:
-        print_exc()
+        logger.error(get_exc())
 
 
-def make_pid_file(pid_file):
-    '''Make pid file at given pid_file location.'''
+class EventHandler(object):
+    '''Event handler class. Used to store args and kwargs which are merged
+    come time to call the callback with the event args and kwargs.'''
 
-    make_dirs(pid_file)
-    fileobj = open(pid_file, 'w')
-    fileobj.write('%d' % os.getpid())
-    fileobj.close()
+    nextid = count().next
 
+    def __init__(self, plugin, event, callback, args, kwargs):
+        self.id = self.nextid()
+        self.plugin = plugin
+        self.event = event
+        self.callback = callback
+        self.args = args
+        self.kwargs = kwargs
 
-def del_pid_file(pid_file):
-    '''Delete pid file at given pid_file location.'''
 
-    if os.path.isfile(pid_file):
-        os.remove(pid_file)
+    def __repr__(self):
+        elems = ['id=%d' % self.id, 'event=%s' % self.event,
+            'callback=%r' % self.callback]
 
+        if self.args:
+            elems.append('args=%s' % repr(self.args))
 
-def get_pid(pid_file):
-    '''Read pid from pid_file.'''
+        if self.kwargs:
+            elems.append('kwargs=%s' % repr(self.kwargs))
 
-    try:
-        fileobj = open(pid_file, 'r')
-        pid = int(fileobj.read())
-        fileobj.close()
-        return pid
+        elems.append('plugin=%s' % self.plugin.name)
+        return u'<handler(%s)>' % ', '.join(elems)
 
-    except IOError, ValueError:
-        print_exc()
-        return None
 
+    def call(self, uzbl, *args, **kwargs):
+        '''Execute the handler function and merge argument lists.'''
 
-def pid_running(pid):
-    '''Returns True if a process with the given pid is running.'''
+        args = args + self.args
+        kwargs = dict(self.kwargs.items() + kwargs.items())
+        self.callback(uzbl, *args, **kwargs)
 
-    try:
-        os.kill(pid, 0)
 
-    except OSError:
-        return False
+class Plugin(object):
+    '''Plugin module wrapper object.'''
 
-    else:
-        return True
+    # Special functions exported from the Plugin instance to the
+    # plugin namespace.
+    special_functions = ['require', 'export', 'export_dict', 'connect',
+            'connect_dict', 'logger']
 
 
-def term_process(pid):
-    '''Send a SIGTERM signal to the process with the given pid.'''
+    def __init__(self, parent, name, path, plugin):
+        self.parent = parent
+        self.name = name
+        self.path = path
+        self.plugin = plugin
+        self.logger = get_logger('plugin.%s' % name)
 
-    if not pid_running(pid):
-        return False
+        # Weakrefs to all handlers created by this plugin
+        self.handlers = set([])
 
-    os.kill(pid, SIGTERM)
+        # Plugins init hook
+        self.init = getattr(plugin, 'init')
 
-    start = time.time()
-    while True:
-        if not pid_running(pid):
-            return True
+        # Plugins optional after hook
+        after = getattr(plugin, 'after', None)
+        self.after = after if callable(after) else None
 
-        if time.time() - start > 5:
-            raise OSError('failed to stop process with pid: %d' % pid)
+        # Plugins optional cleanup hook
+        cleanup = getattr(plugin, 'cleanup', None)
+        self.cleanup = cleanup if callable(cleanup) else None
 
-        time.sleep(0.25)
+        # Export plugin's instance methods to plugin namespace
+        for attr in self.special_functions:
+            plugin.__dict__[attr] = getattr(self, attr)
 
 
-def parse_msg(uzbl, msg):
-    '''Parse an incoming msg from a uzbl instance. All non-event messages
-    will be printed here and not be passed to the uzbl instance event
-    handler function.'''
+    def __repr__(self):
+        return u'<plugin(%r)>' % self.plugin
 
-    if not msg:
-        return
 
-    cmd = FINDSPACES.split(msg, 3)
-    if not cmd or cmd[0] != 'EVENT':
-        # Not an event message.
-        print '---', msg.encode('utf-8')
-        return
+    def export(self, uzbl, attr, object, prepend=True):
+        '''Attach `object` to `uzbl` instance. This is the preferred method
+        of sharing functionality, functions, data and objects between
+        plugins.
 
-    while len(cmd) < 4:
-        cmd.append('')
+        If the object is callable you may wish to turn the callable object
+        in to a meta-instance-method by prepending `uzbl` to the call stack.
+        You can change this behaviour with the `prepend` argument.
+        '''
 
-    event, args = cmd[2], cmd[3]
-    if not event:
-        return
+        assert attr not in uzbl.exports, "attr %r already exported by %r" %\
+            (attr, uzbl.exports[attr][0])
 
-    try:
-        uzbl.event(event, args)
+        prepend = True if prepend and callable(object) else False
+        uzbl.__dict__[attr] = partial(object, uzbl) if prepend else object
+        uzbl.exports[attr] = (self, object, prepend)
+        uzbl.logger.info('exported %r to %r by plugin %r, prepended %r'
+            % (object, 'uzbl.%s' % attr, self.name, prepend))
 
-    except:
-        print_exc()
 
+    def export_dict(self, uzbl, exports):
+        for (attr, object) in exports.items():
+            self.export(uzbl, attr, object)
 
-class EventHandler(object):
 
-    nexthid = count().next
+    def find_handler(self, event, callback, args, kwargs):
+        '''Check if a handler with the identical callback and arguments
+        exists and return it.'''
 
-    def __init__(self, event, handler, *args, **kargs):
-        if not callable(handler):
-            raise ArgumentError("EventHandler object requires a callable "
-                "object function for the handler argument not: %r" % handler)
+        # Remove dead refs
+        self.handlers -= set(filter(lambda ref: not ref(), self.handlers))
 
-        self.function = handler
-        self.args = args
-        self.kargs = kargs
-        self.event = event
-        self.hid = self.nexthid()
+        # Find existing identical handler
+        for handler in [ref() for ref in self.handlers]:
+            if handler.event == event and handler.callback == callback \
+              and handler.args == args and handler.kwargs == kwargs:
+                return handler
 
 
-    def __repr__(self):
-        args = ["event=%s" % self.event, "hid=%d" % self.hid,
-            "function=%r" % self.function]
+    def connect(self, uzbl, event, callback, *args, **kwargs):
+        '''Create an event handler object which handles `event` events.
 
-        if self.args:
-            args.append(u"args=%r" % unicode(self.args))
+        Arguments passed to the connect function (`args` and `kwargs`) are
+        stored in the handler object and merged with the event arguments
+        come handler execution.
 
-        if self.kargs:
-            args.append(u"kargs=%r" % unicode(self.kargs))
+        All handler functions must behave like a `uzbl` instance-method (that
+        means `uzbl` is prepended to the callback call arguments).'''
 
-        return u"<EventHandler(%s)>" % ', '.join(args)
+        # Sanitise and check event name
+        event = event.upper().strip()
+        assert event and ' ' not in event
 
+        assert callable(callback), 'callback must be callable'
 
-class UzblInstance(object):
+        # Check if an identical handler already exists
+        handler = self.find_handler(event, callback, args, kwargs)
+        if not handler:
+            # Create a new handler
+            handler = EventHandler(self, event, callback, args, kwargs)
+            self.handlers.add(weakref.ref(handler))
+            self.logger.info('new %r' % handler)
 
-    # Give all plugins access to the main config dict.
-    global_config = CONFIG
+        uzbl.handlers[event].append(handler)
+        uzbl.logger.info('connected %r' % handler)
+        return handler
 
-    def __init__(self, parent, client_socket):
 
-        # Internal variables.
-        self.exports = {}
-        self.handlers = {}
-        self.parent = parent
-        self.client_socket = client_socket
+    def connect_dict(self, uzbl, connects):
+        for (event, callback) in connects.items():
+            self.connect(uzbl, event, callback)
 
-        self.depth = 0
-        self.buffer = ''
-        self.pid = None
 
-        # Call the init function in every plugin. The init function in each
-        # plugin is where that plugin connects functions to events and exports
-        # functions to the uzbl object.
-        for plugin in self.parent['plugins'].values():
-            try:
-                plugin.init(self)
+    def require(self, plugin):
+        '''Check that plugin with name `plugin` has been loaded. Use this to
+        ensure that your plugins dependencies have been met.'''
 
-            except:
-                raise
+        assert plugin in self.parent.plugins, self.logger.critical(
+            'plugin %r required by plugin %r' (plugin, self.name))
 
 
-    def send(self, msg):
-        '''Send a command to the uzbl instance via the socket file.'''
+class Uzbl(object):
+    def __init__(self, parent, child_socket):
+        self.opts = opts
+        self.parent = parent
+        self.child_socket = child_socket
+        self.time = time.time()
+        self.pid = None
+        self.name = None
 
-        msg = msg.strip()
-        if self.client_socket:
-            print (u'%s<-- %s' % ('  ' * self.depth, msg)).encode('utf-8')
-            self.client_socket.send(("%s\n" % msg).encode('utf-8'))
-
-        else:
-            print (u'%s!-- %s' % ('  ' * self.depth, msg)).encode('utf-8')
-
-
-    def export(self, attr, object, prepend=True):
-        '''Attach an object to the current class instance. This is the
-        preferred method of sharing functionality, functions and objects
-        between plugins.
-
-        If the object is callable you may wish to turn the callable object in
-        to an "instance method call" by using the `functools.partial(..)`
-        tool to prepend the `self` object to the callable objects argument
-        list.
-
-        Example session from a plugins POV:
-          >>> config_dict = {'foo': 'data..', 'bar': 'other data..'}
-          >>> uzbl.export('config', config_dict)
-          >>> uzbl.config is config_dict
-          True
-          >>> print uzbl.config['foo']
-          data..
-          >>> uzbl.export('get', lambda uzbl, key: uzbl.config[key])
-          >>> print uzbl.get('bar')
-          other data..
-        '''
+        # Flag if the instance has raised the INSTANCE_START event.
+        self.instance_start = False
 
-        if prepend and callable(object):
-            object = partial(object, self)
+        # Use name "unknown" until name is discovered.
+        self.logger = get_logger('uzbl-instance[]')
 
-        self.__dict__.__setitem__(attr, object)
+        # Track plugin event handlers and exported functions.
+        self.exports = {}
+        self.handlers = defaultdict(list)
 
+        # Internal vars
+        self._depth = 0
+        self._buffer = ''
 
-    def export_dict(self, export_dict):
-        '''Export multiple (attr, object)'s at once inside a dict of the
-        form `{attr1: object1, attr2: object2, ...}`.'''
 
-        for (attr, object) in export_dict.items():
-            self.export(attr, object)
+    def __repr__(self):
+        return '<uzbl(%s)>' % ', '.join([
+            'pid=%s' % (self.pid if self.pid else "Unknown"),
+            'name=%s' % ('%r' % self.name if self.name else "Unknown"),
+            'uptime=%f' % (time.time()-self.time),
+            '%d exports' % len(self.exports.keys()),
+            '%d handlers' % sum([len(l) for l in self.handlers.values()])])
 
 
-    def connect(self, event, handler, *args, **kargs):
-        '''Connect a uzbl event with a handler. Handlers can either be a
-        function or a uzbl command string.'''
+    def init_plugins(self):
+        '''Call the init and after hooks in all loaded plugins for this
+        instance.'''
 
-        event = event.upper().strip()
-        assert event and ' ' not in event
+        # Initialise each plugin with the current uzbl instance.
+        for plugin in self.parent.plugins.values():
+            self.logger.debug('calling %r plugin init hook' % plugin.name)
+            plugin.init(self)
 
-        if event not in self.handlers.keys():
-            self.handlers[event] = []
+        # Allow plugins to use exported features of other plugins by calling an
+        # optional `after` function in the plugins namespace.
+        for plugin in self.parent.plugins.values():
+            if plugin.after:
+                self.logger.debug('calling %r plugin after hook'%plugin.name)
+                plugin.after(self)
 
-        handlerobj = EventHandler(event, handler, *args, **kargs)
-        self.handlers[event].append(handlerobj)
-        print handlerobj
 
+    def send(self, msg):
+        '''Send a command to the uzbl instance via the child socket
+        instance.'''
 
-    def connect_dict(self, connect_dict):
-        '''Connect a dictionary comprising of {"EVENT_NAME": handler, ..} to
-        the event handler stack.
+        msg = msg.strip()
+        assert self.child_socket, "socket inactive"
 
-        If you need to supply args or kargs to an event use the normal connect
-        function.'''
+        if opts.print_events:
+            print ascii(u'%s<-- %s' % ('  ' * self._depth, msg))
 
-        for (event, handler) in connect_dict.items():
-            self.connect(event, handler)
+        self.child_socket.send(ascii("%s\n" % msg))
 
 
-    def remove_by_id(self, hid):
-        '''Remove connected event handler by unique handler id.'''
+    def read(self):
+        '''Read data from the child socket and pass lines to the parse_msg
+        function.'''
 
-        for (event, handlers) in self.handlers.items():
-            for handler in list(handlers):
-                if hid != handler.hid:
-                    continue
+        try:
+            raw = unicode(self.child_socket.recv(8192), 'utf-8', 'ignore')
+            if not raw:
+                self.logger.debug('read null byte')
+                return self.close()
 
-                echo("removed %r" % handler)
-                handlers.remove(handler)
-                return
+        except:
+            self.logger.error(get_exc())
+            return self.close()
 
-        echo('unable to find & remove handler with id: %d' % hid)
+        lines = (self._buffer + raw).split('\n')
+        self._buffer = lines.pop()
 
+        for line in filter(None, map(unicode.strip, lines)):
+            try:
+                self.parse_msg(line.strip())
+
+            except:
+                self.logger.error(get_exc())
+                self.logger.error('erroneous event: %r' % line)
 
-    def remove(self, handler):
-        '''Remove connected event handler.'''
 
-        for (event, handlers) in self.handlers.items():
-            if handler in handlers:
-                echo("removed %r" % handler)
-                handlers.remove(handler)
-                return
+    def parse_msg(self, line):
+        '''Parse an incoming message from a uzbl instance. Event strings
+        will be parsed into `self.event(event, args)`.'''
 
-        echo('unable to find & remove handler: %r' % handler)
+        # Split by spaces (and fill missing with nulls)
+        elems = (line.split(' ', 3) + ['',]*3)[:4]
 
+        # Ignore non-event messages.
+        if elems[0] != 'EVENT':
+            logger.info('non-event message: %r' % line)
+            if opts.print_events:
+                print '--- %s' % ascii(line)
+            return
 
-    def exec_handler(self, handler, *args, **kargs):
-        '''Execute event handler function.'''
+        # Check event string elements
+        (name, event, args) = elems[1:]
+        assert name and event, 'event string missing elements'
+        if not self.name:
+            self.name = name
+            self.logger = get_logger('uzbl-instance%s' % name)
+            self.logger.info('found instance name %r' % name)
 
-        args += handler.args
-        kargs = dict(handler.kargs.items()+kargs.items())
-        handler.function(self, *args, **kargs)
+        assert self.name == name, 'instance name mismatch'
+
+        # Handle the event with the event handlers through the event method
+        self.event(event, args)
 
 
     def event(self, event, *args, **kargs):
         '''Raise an event.'''
 
         event = event.upper()
-        elems = [event,]
-        if args: elems.append(unicode(args))
-        if kargs: elems.append(unicode(kargs))
-        print (u'%s--> %s' % ('  ' * self.depth, ' '.join(elems))).encode('utf-8')
+
+        if not opts.daemon_mode and opts.print_events:
+            elems = [event,]
+            if args: elems.append(unicode(args))
+            if kargs: elems.append(unicode(kargs))
+            print ascii(u'%s--> %s' % ('  ' * self._depth, ' '.join(elems)))
 
         if event == "INSTANCE_START" and args:
+            assert not self.instance_start, 'instance already started'
+
             self.pid = int(args[0])
+            self.logger.info('found instance pid %r' % self.pid)
+
+            self.init_plugins()
+
+        elif event == "INSTANCE_EXIT":
+            self.logger.info('uzbl instance exit')
+            self.close()
 
         if event not in self.handlers:
             return
 
         for handler in self.handlers[event]:
-            self.depth += 1
+            self._depth += 1
             try:
-                self.exec_handler(handler, *args, **kargs)
+                handler.call(self, *args, **kargs)
 
             except:
-                print_exc()
+                self.logger.error(get_exc())
+
+            self._depth -= 1
+
 
-            self.depth -= 1
+    def close_connection(self, child_socket):
+        '''Close child socket and delete the uzbl instance created for that
+        child socket connection.'''
 
 
     def close(self):
-        '''Close the client socket and clean up.'''
+        '''Close the client socket and call the plugin cleanup hooks.'''
+
+        self.logger.debug('called close method')
+
+        # Remove self from parent uzbls dict.
+        if self.child_socket in self.parent.uzbls:
+            self.logger.debug('removing self from uzbls list')
+            del self.parent.uzbls[self.child_socket]
 
         try:
-            self.client_socket.close()
+            if self.child_socket:
+                self.logger.debug('closing child socket')
+                self.child_socket.close()
 
         except:
-            pass
+            self.logger.error(get_exc())
+
+        finally:
+            self.child_socket = None
 
-        for (name, plugin) in self.parent['plugins'].items():
-            if hasattr(plugin, 'cleanup'):
+        # Call plugins cleanup hooks.
+        for plugin in self.parent.plugins.values():
+            if plugin.cleanup:
+                self.logger.debug('calling %r plugin cleanup hook'
+                    % plugin.name)
                 plugin.cleanup(self)
 
+        logger.info('removed %r' % self)
 
-class UzblEventDaemon(dict):
-    def __init__(self):
 
-        # Init variables and dict keys.
-        dict.__init__(self, {'uzbls': {}})
-        self.running = None
+class UzblEventDaemon(object):
+    def __init__(self):
+        self.opts = opts
         self.server_socket = None
-        self.socket_location = None
+        self._quit = False
+
+        # Hold uzbl instances
+        # {child socket: Uzbl instance, ..}
+        self.uzbls = {}
+
+        # Hold plugins
+        # {plugin name: Plugin instance, ..}
+        self.plugins = {}
 
         # Register that the event daemon server has started by creating the
         # pid file.
-        make_pid_file(CONFIG['pid_file'])
+        make_pid_file(opts.pid_file)
 
         # Register a function to clean up the socket and pid file on exit.
         atexit.register(self.quit)
 
-        # Make SIGTERM act orderly.
-        signal(SIGTERM, lambda signum, stack_frame: sys.exit(1))
+        # Add signal handlers.
+        for sigint in [SIGTERM, SIGINT]:
+            signal(sigint, self.quit)
 
-        # Load plugins, first-build of the plugins may be a costly operation.
-        self['plugins'] = load_plugins(CONFIG['plugin_dirs'],
-            CONFIG['plugins_load'], CONFIG['plugins_ignore'])
+        # Load plugins into self.plugins
+        self.load_plugins(opts.plugins)
 
 
-    def _create_server_socket(self):
-        '''Create the event manager daemon socket for uzbl instance duplex
-        communication.'''
+    def load_plugins(self, plugins):
+        '''Load event manager plugins.'''
 
-        server_socket = CONFIG['server_socket']
-        server_socket = os.path.realpath(os.path.expandvars(server_socket))
-        self.socket_location = server_socket
+        for path in plugins:
+            logger.debug('loading plugin %r' % path)
+            (dir, file) = os.path.split(path)
+            name = file[:-3] if file.lower().endswith('.py') else file
 
-        # Delete socket if it exists.
-        if os.path.exists(server_socket):
-            os.remove(server_socket)
+            info = imp.find_module(name, [dir,])
+            module = imp.load_module(name, *info)
+            assert callable(getattr(module, 'init', None)),\
+                "plugin missing init function: %r" % module
 
-        self.server_socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
-        self.server_socket.bind(server_socket)
-        self.server_socket.listen(5)
+            logger.debug('creating plugin instance for %r plugin' % name)
+            plugin = Plugin(self, name, path, module)
+            self.plugins[name] = plugin
+            logger.info('new %r' % plugin)
 
 
-    def _close_server_socket(self):
-        '''Close and delete the server socket.'''
+    def create_server_socket(self):
+        '''Create the event manager daemon socket for uzbl instance duplex
+        communication.'''
 
-        try:
-            self.server_socket.close()
-            self.server_socket = None
+        # Close old socket.
+        self.close_server_socket()
 
-            if os.path.exists(self.socket_location):
-                os.remove(self.socket_location)
+        sock = socket(AF_UNIX, SOCK_STREAM)
+        sock.bind(opts.server_socket)
+        sock.listen(5)
 
-        except:
-            pass
+        self.server_socket = sock
+        logger.debug('bound server socket to %r' % opts.server_socket)
 
 
     def run(self):
         '''Main event daemon loop.'''
 
-        # Create event daemon socket.
-        self._create_server_socket()
-        echo('listening on: %s' % self.socket_location)
+        logger.debug('entering main loop')
+
+        # Create and listen on the server socket
+        self.create_server_socket()
 
-        if CONFIG['daemon_mode']:
-            echo('entering daemon mode.')
+        if opts.daemon_mode:
+            # Daemonize the process
             daemonize()
-            # The pid has changed so update the pid file.
-            make_pid_file(CONFIG['pid_file'])
 
-        # Now listen for incoming connections and or data.
-        self.listen()
+            # Update the pid file
+            make_pid_file(opts.pid_file)
+
+        try:
+            # Accept incoming connections and listen for incoming data
+            self.listen()
+
+        except:
+            if not self._quit:
+                logger.critical(get_exc())
 
-        # Clean up.
+        # Clean up and exit
         self.quit()
 
+        logger.debug('exiting main loop')
+
 
     def listen(self):
         '''Accept incoming connections and constantly poll instance sockets
         for incoming data.'''
 
-        self.running = True
-        while self.running:
+        logger.info('listening on %r' % opts.server_socket)
 
-            sockets = [self.server_socket] + self['uzbls'].keys()
+        # Count accepted connections
+        connections = 0
 
-            reads, _, errors = select(sockets, [], sockets, 1)
+        while (self.uzbls or not connections) or (not opts.auto_close):
+            socks = [self.server_socket] + self.uzbls.keys()
+            reads, _, errors = select(socks, [], socks, 1)
 
             if self.server_socket in reads:
-                self.accept_connection()
                 reads.remove(self.server_socket)
 
-            for client in reads:
-                self.read_socket(client)
+                # Accept connection and create uzbl instance.
+                child_socket = self.server_socket.accept()[0]
+                self.uzbls[child_socket] = Uzbl(self, child_socket)
+                connections += 1
+
+            for uzbl in [self.uzbls[s] for s in reads]:
+                uzbl.read()
+
+            for uzbl in [self.uzbls[s] for s in errors]:
+                uzbl.logger.error('socket read error')
+                uzbl.close()
 
-            for client in errors:
-                error('Unknown error on socket: %r' % client)
-                self.close_connection(client)
+        logger.info('auto closing')
 
 
-    def read_socket(self, client):
-        '''Read data from an instance socket and pass to the uzbl objects
-        event handler function.'''
+    def close_server_socket(self):
+        '''Close and delete the server socket.'''
 
-        uzbl = self['uzbls'][client]
         try:
-            raw = unicode(client.recv(8192), 'utf-8', 'ignore')
+            if self.server_socket:
+                logger.debug('closing server socket')
+                self.server_socket.close()
+                self.server_socket = None
+
+            if os.path.exists(opts.server_socket):
+                logger.info('unlinking %r' % opts.server_socket)
+                os.unlink(opts.server_socket)
 
         except:
-            print_exc()
-            raw = None
+            logger.error(get_exc())
 
-        if not raw:
-            # Read null byte, close socket.
-            return self.close_connection(client)
 
-        uzbl.buffer += raw
-        msgs = uzbl.buffer.split('\n')
-        uzbl.buffer = msgs.pop()
+    def quit(self, sigint=None, *args):
+        '''Close all instance socket objects, server socket and delete the
+        pid file.'''
 
-        for msg in msgs:
-            try:
-                parse_msg(uzbl, msg.strip())
+        if sigint == SIGTERM:
+            logger.critical('caught SIGTERM, exiting')
 
-            except:
-                print_exc()
+        elif sigint == SIGINT:
+            logger.critical('caught SIGINT, exiting')
 
+        elif not self._quit:
+            logger.debug('shutting down event manager')
 
-    def accept_connection(self):
-        '''Accept incoming connection to the server socket.'''
+        self.close_server_socket()
 
-        client_socket = self.server_socket.accept()[0]
+        for uzbl in self.uzbls.values():
+            uzbl.close()
 
-        uzbl = UzblInstance(self, client_socket)
-        self['uzbls'][client_socket] = uzbl
+        del_pid_file(opts.pid_file)
 
+        if not self._quit:
+            logger.info('event manager shut down')
+            self._quit = True
 
-    def close_connection(self, client):
-        '''Clean up after instance close.'''
 
+def make_pid_file(pid_file):
+    '''Creates a pid file at `pid_file`, fails silently.'''
+
+    try:
+        logger.debug('creating pid file %r' % pid_file)
+        make_dirs(pid_file)
+        pid = os.getpid()
+        fileobj = open(pid_file, 'w')
+        fileobj.write('%d' % pid)
+        fileobj.close()
+        logger.info('created pid file %r with pid %d' % (pid_file, pid))
+
+    except:
+        logger.error(get_exc())
+
+
+def del_pid_file(pid_file):
+    '''Deletes a pid file at `pid_file`, fails silently.'''
+
+    if os.path.isfile(pid_file):
         try:
-            if client in self['uzbls']:
-                uzbl = self['uzbls'][client]
-                uzbl.close()
-                del self['uzbls'][client]
+            logger.debug('deleting pid file %r' % pid_file)
+            os.remove(pid_file)
+            logger.info('deleted pid file %r' % pid_file)
 
         except:
-            print_exc()
+            logger.error(get_exc())
 
-        if not len(self['uzbls']) and CONFIG['auto_close']:
-            echo('auto closing event manager.')
-            self.running = False
 
+def get_pid(pid_file):
+    '''Reads a pid from pid file `pid_file`, fails None.'''
 
-    def quit(self):
-        '''Close all instance socket objects, server socket and delete the
-        pid file.'''
+    try:
+        logger.debug('reading pid file %r' % pid_file)
+        fileobj = open(pid_file, 'r')
+        pid = int(fileobj.read())
+        fileobj.close()
+        logger.info('read pid %d from pid file %r' % (pid, pid_file))
+        return pid
 
-        echo('shutting down event manager.')
+    except (IOError, ValueError):
+        logger.error(get_exc())
+        return None
 
-        for client in self['uzbls'].keys():
-            self.close_connection(client)
 
-        echo('unlinking: %r' % self.socket_location)
-        self._close_server_socket()
+def pid_running(pid):
+    '''Checks if a process with a pid `pid` is running.'''
 
-        echo('deleting pid file: %r' % CONFIG['pid_file'])
-        del_pid_file(CONFIG['pid_file'])
+    try:
+        os.kill(pid, 0)
+    except OSError:
+        return False
+    else:
+        return True
+
+
+def term_process(pid):
+    '''Asks nicely then forces process with pid `pid` to exit.'''
+
+    try:
+        logger.info('sending SIGTERM to process with pid %r' % pid)
+        os.kill(pid, SIGTERM)
+
+    except OSError:
+        logger.error(get_exc())
+
+    logger.debug('waiting for process with pid %r to exit' % pid)
+    start = time.time()
+    while True:
+        if not pid_running(pid):
+            logger.debug('process with pid %d exit' % pid)
+            return True
+
+        if (time.time()-start) > 5:
+            logger.warning('process with pid %d failed to exit' % pid)
+            logger.info('sending SIGKILL to process with pid %d' % pid)
+            try:
+                os.kill(pid, SIGKILL)
+            except:
+                logger.critical(get_exc())
+                raise
+
+        if (time.time()-start) > 10:
+            logger.critical('unable to kill process with pid %d' % pid)
+            raise OSError
+
+        time.sleep(0.25)
 
 
 def stop_action():
     '''Stop the event manager daemon.'''
 
-    pid_file = CONFIG['pid_file']
+    pid_file = opts.pid_file
     if not os.path.isfile(pid_file):
-        return echo('no running daemon found.')
+        logger.error('could not find running event manager with pid file %r'
+            % opts.pid_file)
+        return
 
-    echo('found pid file: %r' % pid_file)
     pid = get_pid(pid_file)
     if not pid_running(pid):
-        echo('no process with pid: %d' % pid)
-        return os.remove(pid_file)
+        logger.debug('no process with pid %r' % pid)
+        del_pid_file(pid_file)
+        return
 
-    echo("terminating process with pid: %d" % pid)
+    logger.debug('terminating process with pid %r' % pid)
     term_process(pid)
-    if os.path.isfile(pid_file):
-        os.remove(pid_file)
-
-    echo('stopped event daemon.')
+    del_pid_file(pid_file)
+    logger.info('stopped event manager process with pid %d' % pid)
 
 
 def start_action():
     '''Start the event manager daemon.'''
 
-    pid_file = CONFIG['pid_file']
+    pid_file = opts.pid_file
     if os.path.isfile(pid_file):
-        echo('found pid file: %r' % pid_file)
         pid = get_pid(pid_file)
         if pid_running(pid):
-            return echo('event daemon already started with pid: %d' % pid)
+            logger.error('event manager already started with pid %d' % pid)
+            return
 
-        echo('no process with pid: %d' % pid)
-        os.remove(pid_file)
+        logger.info('no process with pid %d' % pid)
+        del_pid_file(pid_file)
 
-    echo('starting event manager.')
     UzblEventDaemon().run()
 
 
 def restart_action():
     '''Restart the event manager daemon.'''
 
-    echo('restarting event manager daemon.')
     stop_action()
     start_action()
 
 
 def list_action():
-    '''List all the plugins being loaded by the event daemon.'''
+    '''List all the plugins that would be loaded in the current search
+    dirs.'''
 
-    plugins = find_plugins(CONFIG['plugin_dirs'])
-    dirs = {}
+    names = {}
+    for plugin in opts.plugins:
+        (head, tail) = os.path.split(plugin)
+        if tail not in names:
+            names[tail] = plugin
 
-    for (plugin, plugin_dir) in plugins.items():
-        if plugin_dir not in dirs:
-            dirs[plugin_dir] = []
+    for plugin in sorted(names.values()):
+        print plugin
 
-        dirs[plugin_dir].append(plugin)
 
-    for (index, (plugin_dir, plugin_list)) in enumerate(sorted(dirs.items())):
-        if index:
-            print
+if __name__ == "__main__":
+    parser = OptionParser('usage: %prog [options] {start|stop|restart|list}')
+    add = parser.add_option
 
-        print "%s:" % plugin_dir
-        for plugin in sorted(plugin_list):
-            print "    %s" % plugin
+    add('-v', '--verbose',
+        dest='verbose', default=2, action='count',
+        help='increase verbosity')
 
+    add('-d', '--plugin-dir',
+        dest='plugin_dirs', action='append', metavar="DIR", default=[],
+        help='add extra plugin search dir, same as `-l "DIR/*.py"`')
 
-if __name__ == "__main__":
-    USAGE = "usage: %prog [options] {start|stop|restart|list}"
-    PARSER = OptionParser(usage=USAGE)
-    PARSER.add_option('-v', '--verbose', dest='verbose', action="store_true",
-      help="print verbose output.")
+    add('-l', '--load-plugin',
+        dest='load_plugins', action='append', metavar="PLUGIN", default=[],
+        help='load plugin, loads before plugins in search dirs')
 
-    PARSER.add_option('-d', '--plugin-dirs', dest='plugin_dirs', action="store",
-      metavar="DIRS", help="Specify plugin directories in the form of "\
-      "'dir1:dir2:dir3'.")
+    socket_location = os.path.join(CACHE_DIR, 'event_daemon')
+    add('-s', '--server-socket',
+        dest='server_socket', metavar="SOCKET", default=socket_location,
+        help='server AF_UNIX socket location')
 
-    PARSER.add_option('-l', '--load-plugins', dest="load", action="store",
-      metavar="PLUGINS", help="comma separated list of plugins to load")
+    add('-p', '--pid-file',
+        metavar="FILE", dest='pid_file',
+        help='pid file location, defaults to server socket + .pid')
 
-    PARSER.add_option('-i', '--ignore-plugins', dest="ignore", action="store",
-      metavar="PLUGINS", help="comma separated list of plugins to ignore")
+    add('-n', '--no-daemon',
+        dest='daemon_mode', action='store_false', default=True,
+        help='daemonize the process')
 
-    PARSER.add_option('-p', '--pid-file', dest='pid', action='store',
-      metavar='FILE', help="specify pid file location")
+    add('-a', '--auto-close',
+        dest='auto_close', action='store_true', default=False,
+        help='auto close after all instances disconnect')
 
-    PARSER.add_option('-s', '--server-socket', dest='socket', action='store',
-      metavar='SOCKET', help="specify the daemon socket location")
+    add('-i', '--no-default-dirs',
+        dest='default_dirs', action='store_false', default=True,
+        help='ignore the default plugin search dirs')
 
-    PARSER.add_option('-n', '--no-daemon', dest="daemon",
-      action="store_true", help="don't enter daemon mode.")
+    add('-o', '--log-file',
+        dest='log_file', metavar='FILE',
+        help='write logging output to a file, defaults to server socket +'
+        ' .log')
 
-    PARSER.add_option('-a', '--auto-close', dest='autoclose',
-      action='store_true', help='auto close after all instances disconnect.')
+    add('-q', '--quiet-events',
+        dest='print_events', action="store_false", default=True,
+        help="silence the printing of events to stdout")
 
-    (OPTIONS, ARGS) = PARSER.parse_args()
+    (opts, args) = parser.parse_args()
 
-    # init like {start|stop|..} daemon actions dict.
-    DAEMON_ACTIONS = {'start': start_action, 'stop': stop_action,
-        'restart': restart_action, 'list': list_action}
+    opts.server_socket = expandpath(opts.server_socket)
+
+    # Set default pid file location
+    if not opts.pid_file:
+        opts.pid_file = "%s.pid" % opts.server_socket
 
-    if not ARGS:
-        ACTION = 'start'
+    else:
+        opts.pid_file = expandpath(opts.pid_file)
 
-    elif len(ARGS) == 1:
-        ACTION = ARGS[0]
-        if ACTION not in DAEMON_ACTIONS:
-            raise ArgumentError("unknown argument: %r" % ACTION)
+    # Set default log file location
+    if not opts.log_file:
+        opts.log_file = "%s.log" % opts.server_socket
 
     else:
-        raise ArgumentError("too many arguments: %r" % ARGS)
+        opts.log_file = expandpath(opts.log_file)
+
+    # Logging setup
+    log_level = logging.CRITICAL - opts.verbose*10
+
+    # Console logging handler
+    ch = logging.StreamHandler()
+    ch.setLevel(max(log_level+10, 10))
+    ch.setFormatter(logging.Formatter(
+        '%(name)s: %(levelname)s: %(message)s'))
+
+    # File logging handler
+    fh = logging.FileHandler(opts.log_file, 'w', 'utf-8', 1)
+    fh.setLevel(max(log_level, 10))
+    fh.setFormatter(logging.Formatter(
+        '[%(created)f] %(name)s: %(levelname)s: %(message)s'))
+
+    # logging.getLogger wrapper which sets the levels and adds the
+    # file and console handlers automagically
+    def get_logger(name):
+        handlers = [ch, fh]
+        level = [max(log_level, 10),]
+        logger = logging.getLogger(name)
+        logger.setLevel(level[0])
+        for handler in handlers:
+            logger.addHandler(handler)
+
+        return logger
+
+    # Get main logger
+    logger = get_logger(SCRIPTNAME)
+    logger.info('logging to %r' % opts.log_file)
 
-    # parse other flags & options.
-    if OPTIONS.verbose:
-        CONFIG['verbose'] = True
+    plugins = {}
 
-    if OPTIONS.plugin_dirs:
-        PLUGIN_DIRS = []
-        for DIR in OPTIONS.plugin_dirs.split(':'):
-            if not DIR:
-                continue
+    # Load all `opts.load_plugins` into the plugins list
+    for path in opts.load_plugins:
+        path = expandpath(path)
+        matches = glob(path)
+        if not matches:
+            parser.error('cannot find plugin(s): %r' % path)
 
-            PLUGIN_DIRS.append(os.path.realpath(DIR))
+        for plugin in matches:
+            (head, tail) = os.path.split(plugin)
+            if tail not in plugins:
+                logger.debug('found plugin: %r' % plugin)
+                plugins[tail] = plugin
 
-        CONFIG['plugin_dirs'] = PLUGIN_DIRS
-        echo("plugin search dirs: %r" % PLUGIN_DIRS)
+            else:
+                logger.debug('ignoring plugin: %r' % plugin)
 
-    if OPTIONS.load and OPTIONS.ignore:
-        error("you can't load and ignore at the same time.")
-        sys.exit(1)
+    # Add default plugin locations
+    if opts.default_dirs:
+        logger.debug('adding default plugin dirs to plugin dirs list')
+        opts.plugin_dirs += [os.path.join(DATA_DIR, 'plugins/'),
+            os.path.join(PREFIX, 'share/uzbl/examples/data/plugins/')]
+
+    else:
+        logger.debug('ignoring default plugin dirs')
 
-    elif OPTIONS.load:
-        LOAD = CONFIG['plugins_load']
-        for PLUGIN in OPTIONS.load.split(','):
-            if PLUGIN.strip():
-                LOAD.append(PLUGIN.strip())
+    # Load all plugins in `opts.plugin_dirs` into the plugins list
+    for dir in opts.plugin_dirs:
+        dir = expandpath(dir)
+        logger.debug('searching plugin dir: %r' % dir)
+        for plugin in glob(os.path.join(dir, '*.py')):
+            (head, tail) = os.path.split(plugin)
+            if tail not in plugins:
+                logger.debug('found plugin: %r' % plugin)
+                plugins[tail] = plugin
 
-        echo('only loading plugin(s): %s' % ', '.join(LOAD))
+            else:
+                logger.debug('ignoring plugin: %r' % plugin)
 
-    elif OPTIONS.ignore:
-        IGNORE = CONFIG['plugins_ignore']
-        for PLUGIN in OPTIONS.ignore.split(','):
-            if PLUGIN.strip():
-                IGNORE.append(PLUGIN.strip())
+    plugins = plugins.values()
 
-        echo('ignoring plugin(s): %s' % ', '.join(IGNORE))
+    # Check all the paths in the plugins list are files
+    for plugin in plugins:
+        if not os.path.isfile(plugin):
+            parser.error('plugin not a file: %r' % plugin)
 
-    if OPTIONS.autoclose:
-        CONFIG['auto_close'] = True
-        echo('will auto close.')
+    if opts.auto_close: logger.debug('will auto close')
+    else: logger.debug('will not auto close')
 
-    if OPTIONS.pid:
-        CONFIG['pid_file'] = os.path.realpath(OPTIONS.pid)
-        echo("pid file location: %r" % CONFIG['pid_file'])
+    if opts.daemon_mode: logger.debug('will daemonize')
+    else: logger.debug('will not daemonize')
 
-    if OPTIONS.socket:
-        CONFIG['server_socket'] = os.path.realpath(OPTIONS.socket)
-        echo("daemon socket location: %s" % CONFIG['server_socket'])
+    opts.plugins = plugins
+
+    # init like {start|stop|..} daemon actions
+    daemon_actions = {'start': start_action, 'stop': stop_action,
+        'restart': restart_action, 'list': list_action}
+
+    if len(args) == 1:
+        action = args[0]
+        if action not in daemon_actions:
+            parser.error('invalid action: %r' % action)
+
+    elif not args:
+        logger.warning('no daemon action given, assuming %r' % 'start')
+        action = 'start'
+
+    else:
+        parser.error('invalid action argument: %r' % args)
 
-    if OPTIONS.daemon:
-        CONFIG['daemon_mode'] = False
+    logger.info('daemon action %r' % action)
+    # Do action
+    daemon_actions[action]()
 
-    # Now {start|stop|...}
-    DAEMON_ACTIONS[ACTION]()
+    logger.debug('process CPU time: %f' % time.clock())