]> git.llucax.com Git - software/pymin.git/commitdiff
Merge branch 'master' of git.llucax.com.ar:/var/lib/git/software/pymin into logging
authorLeandro Lucarella <llucax@gmail.com>
Mon, 24 Dec 2007 05:24:38 +0000 (02:24 -0300)
committerLeandro Lucarella <llucax@gmail.com>
Mon, 24 Dec 2007 05:24:38 +0000 (02:24 -0300)
* 'master' of git.llucax.com.ar:/var/lib/git/software/pymin:
  Add protocol specification of firewall and nat commands.
  Added the protocol specification.
  Root class inyects ip forwrading in constructor.
  Added route handling capabilities and service restarting
  Fix so that when a device is brought back up, the routes
  Added support to hook services to IPHandler.
  Support for inactive devices added in IPHandler.

Conflicts:

pymin/services/ip/__init__.py

1  2 
config.py
pymin/services/ip/__init__.py
pymin/services/util.py

diff --combined config.py
index e16262d1ee09dcfdf84ae42b162738642df6b025,a0b5498cc228f50a57a330ef3319c239a5c21b47..7a9b60452ddeb6cef41be1a2c78e9a6b5121d8d5
+++ b/config.py
@@@ -1,13 -1,5 +1,13 @@@
  # vim: set et sts=4 sw=4 encoding=utf-8 :
  
 +# First of all, we need to setup the logging framework
 +import logging
 +logging.basicConfig(
 +        level   = logging.DEBUG,
 +        format  = '%(asctime)s %(name)-24s %(levelname)-8s %(message)s',
 +        datefmt = '%a, %d %b %Y %H:%M:%S',
 +)
 +
  from pymin.services import *
  from pymin.dispatcher import Handler
  from os.path import join
@@@ -19,6 -11,12 +19,12 @@@ config_path = join(base_path, 'config'
  
  class Root(Handler):
  
+     def __init__(self):
+         f = file("/proc/sys/net/ipv4/ip_forward","w")
+         f.write("1")
+         f.close()
+         #self.ip.device_up_hook(self.dns)
      firewall = FirewallHandler(
          pickle_dir = join(pickle_path, 'firewall'),
          config_dir = join(config_path, 'firewall'))
index 71354abdbba6983ce20618ec4bed4a17261c01db,b1d50b2262378aed9ca20d1c4d144438a89b757c..a7e23cba0a251b40122f0eb1e8c8ec4eb0ebd922
@@@ -2,15 -2,13 +2,15 @@@
  
  from subprocess import Popen, PIPE
  from os import path
 +import logging ; log = logging.getLogger('pymin.services.ip')
  
  from pymin.seqtools import Sequence
  from pymin.dispatcher import handler, HandlerError, Handler
  from pymin.services.util import Restorable, ConfigWriter, InitdHandler, \
                                  TransactionalHandler, SubHandler, call, \
                                  get_network_devices, ListComposedSubHandler, \
 -                                DictComposedSubHandler, Device, Address, ExecutionError
 +                                DictComposedSubHandler, Device, Address, \
 +                                ExecutionError
  
  __ALL__ = ('IpHandler',)
  
@@@ -94,19 -92,51 +94,51 @@@ class Route(Sequence)
          self.net_addr = net_addr
          self.prefix = prefix
          self.gateway = gateway
      def update(self, net_addr=None, prefix=None, gateway=None):
          if net_addr is not None: self.net_addr = net_addr
          if prefix is not None: self.prefix = prefix
          if gateway is not None: self.gateway = gateway
      def as_tuple(self):
          return(self.net_addr, self.prefix, self.gateway)
  
+     def __cmp__(self, other):
+         if self.net_addr == other.net_addr \
+                 and self.prefix == other.prefix \
+                 and self.gateway == other.gateway:
+             return 0
+         return cmp(id(self), id(other))
  class RouteHandler(ListComposedSubHandler):
      handler_help = u"Manage IP routes"
      _comp_subhandler_cont = 'devices'
      _comp_subhandler_attr = 'routes'
      _comp_subhandler_class = Route
  
+     @handler(u'Adds a route to : ip route add <net_addr> <prefix> <gateway> [device]')
+     def add(self, net_addr, prefix, gateway, dev=None):
+         if dev is not None:
+             ListComposedSubHandler.add(self, dev, net_addr, prefix, gateway)
+         else:
+             r = Route(net_addr, prefix, gateway)
+             if not r in self.parent.no_device_routes:
+                 self.parent.no_device_routes.append(r)
+     @handler("Deletes a route : ip route delete <route_number_in_show> [dev]")
+     def delete(self, index, dev=None):
+         if dev is not None:
+             ListComposedSubHandler.delete(self, dev, index)
+         else:
+             i = int(index)
+             del self.parent.no_device_routes[i]
+     @handler("Shows routes : ip route show [dev]")
+     def show(self, dev=None):
+         if dev is not None:
+             return ListComposedSubHandler.show(self, dev)
+         else:
+             return self.parent.no_device_routes
  
  class AddressHandler(DictComposedSubHandler):
      handler_help = u"Manage IP addresses"
@@@ -120,7 -150,6 +152,7 @@@ class DeviceHandler(SubHandler)
      handler_help = u"Manage network devices"
  
      def __init__(self, parent):
 +        log.debug(u'DeviceHandler(%r)', parent)
          # FIXME remove templates to execute commands
          from mako.template import Template
          self.parent = parent
  
      @handler(u'Bring the device up')
      def up(self, name):
 +        log.debug(u'DeviceHandler.up(%r)', name)
          if name in self.parent.devices:
              call(self.device_template.render(dev=name, action='up'), shell=True)
 -                    print e
+             #bring up all the route asocitaed to the device
+             for route in self.parent.devices[name].routes:
+                 try:
++                    log.debug(u'IpHandler.up: adding %r', route)
+                     call(self.parent._render_config('route_add', dict(
+                             dev = name,
+                             net_addr = route.net_addr,
+                             prefix = route.prefix,
+                             gateway = route.gateway,
+                         )
+                     ), shell=True)
+                 except ExecutionError, e:
++                    log.debug(u'IpHandler.up: error adding %r -> %r', route, e)
+             self.parent._bring_up_no_dev_routes()
+             self.parent._restart_services()
          else:
 +            log.debug(u'DeviceHandler.up: device not found')
              raise DeviceNotFoundError(name)
  
      @handler(u'Bring the device down')
      def down(self, name):
 +        log.debug(u'DeviceHandler.down(%r)', name)
          if name in self.parent.devices:
              call(self.device_template.render(dev=name, action='down'), shell=True)
+             self.parent._bring_up_no_dev_routes()
+             self.parent._restart_services()
          else:
 +            log.debug(u'DeviceHandler.up: device not found')
              raise DeviceNotFoundError(name)
  
      @handler(u'List all devices')
      def list(self):
 +        log.debug(u'DeviceHandler.list()')
          return self.parent.devices.keys()
  
      @handler(u'Get information about a device')
      def show(self):
 +        log.debug(u'DeviceHandler.show()')
          return self.parent.devices.items()
  
  class IpHandler(Restorable, ConfigWriter, TransactionalHandler):
  
      handler_help = u"Manage IP devices, addresses, routes and hops"
  
-     _persistent_attrs = ('devices','hops')
+     _persistent_attrs = ('devices','hops','no_device_routes')
  
      _restorable_defaults = dict(
                              devices=get_network_devices(),
-                             hops = list()
+                             hops = list(),
+                             no_device_routes = list(),
                              )
  
      _config_writer_files = ('device', 'ip_add', 'ip_del', 'ip_flush',
  
      def __init__(self, pickle_dir='.', config_dir='.'):
          r"Initialize DhcpHandler object, see class documentation for details."
 +        log.debug(u'IpHandler(%r, %r)', pickle_dir, config_dir)
          self._persistent_dir = pickle_dir
          self._config_writer_cfg_dir = config_dir
          self._config_build_templates()
          self.route = RouteHandler(self)
          self.dev = DeviceHandler(self)
          self.hop = HopHandler(self)
+         self.no_device_routes = list()
+         self.services = list()
  
      def _write_config(self):
          r"_write_config() -> None :: Execute all commands."
 +        log.debug(u'IpHandler._write_config()')
          for device in self.devices.values():
 +            log.debug(u'IpHandler._write_config: processing device %s', device)
+             if device.active:
+                 self._write_config_for_device(device)
+         self._bring_up_no_dev_routes()
+         self._write_hops()
+     def _bring_up_no_dev_routes(self):
++        log.debug(u'IpHandler._bring_up_no_dev_routes()')
+         for route in self.no_device_routes:
              try:
-                 log.debug(u'IpHandler._write_config: flushing routes...')
-                 call(self._render_config('route_flush', dict(dev=device.name)),
-                         shell=True)
-             except ExecutionError, e:
-                 log.debug(u'IpHandler._write_config: error flushing -> %r', e)
-             try:
-                 log.debug(u'IpHandler._write_config: flushing addrs...')
-                 call(self._render_config('ip_flush', dict(dev=device.name)),
-                         shell=True)
++                log.debug(u'IpHandler._bring_up_no_dev_routes: add %r', route)
+                 call(self._render_config('route_add', dict(
+                         dev = None,
+                         net_addr = route.net_addr,
+                         prefix = route.prefix,
+                         gateway = route.gateway,
+                     )
+                 ), shell=True)
              except ExecutionError, e:
 -                print e
 +                log.debug(u'IpHandler._write_config: error flushing -> %r', e)
-             for address in device.addrs.values():
-                 broadcast = address.broadcast
-                 if broadcast is None:
-                     broadcast = '+'
-                 try:
-                     log.debug(u'IpHandler._write_config: adding %r', address)
-                     call(self._render_config('ip_add', dict(
-                             dev = device.name,
-                             addr = address.ip,
-                             netmask = address.netmask,
-                             peer = address.peer,
-                             broadcast = broadcast,
-                         )), shell=True)
-                 except ExecutionError, e:
-                     log.debug(u'IpHandler._write_config: error adding -> %r', e)
-             for route in device.routes:
-                 try:
-                     log.debug(u'IpHandler._write_config: adding %r', route)
-                     call(self._render_config('route_add', dict(
-                             dev = device.name,
-                             net_addr = route.net_addr,
-                             prefix = route.prefix,
-                             gateway = route.gateway,
-                         )), shell=True)
-                 except ExecutionError, e:
-                     log.debug(u'IpHandler._write_config: error adding -> %r', e)
+     def _write_hops(self):
+         r"_write_hops() -> None :: Execute all hops."
++        log.debug(u'IpHandler._write_hops()')
          if self.hops:
-             log.debug(u'IpHandler._write_config: we have hops: %r', self.hops)
++            log.debug(u'IpHandler._write_hops: we have hops: %r', self.hops)
              try:
-                 log.debug(u'IpHandler._write_config: flushing default route')
++                log.debug(u'IpHandler._write_hops: flushing default hops')
                  call('ip route del default', shell=True)
              except ExecutionError, e:
-                 log.debug(u'IpHandler._write_config: error adding -> %r', e)
 -                print e
++                log.debug(u'IpHandler._write_hops: error adding -> %r', e)
              try:
-                 log.debug(u'IpHandler._write_config: configuring hops')
++                log.debug(u'IpHandler._write_hops: configuring hops')
+                 #get hops for active devices
+                 active_hops = dict()
+                 for h in self.hops:
+                     if h.device in self.devices:
+                         if self.devices[h.device].active:
+                             active_hops.append(h)
                  call(self._render_config('hop', dict(
-                     hops = self.hops,
+                     hops = active_hops,
                          )
                  ), shell=True)
              except ExecutionError, e:
-                 log.debug(u'IpHandler._write_config: error adding -> %r', e)
 -                print e
++                log.debug(u'IpHandler._write_hops: error adding -> %r', e)
+     def _write_config_for_device(self, device):
 -        r"_write_config_for_device(self, device) -> None :: Execute all commands for a device."
++        r"_write_config_for_device(self, device) -> None :: Execute commands."
++        log.debug(u'IpHandler._write_config_for_device()')
+         try:
 -            call(self._render_config('route_flush', dict(dev=device.name)), shell=True)
++            log.debug(u'IpHandler._write_config_for_device: flushing routes...')
++            call(self._render_config('route_flush', dict(dev=device.name)),
++                        shell=True)
+         except ExecutionError, e:
 -            print e
++            log.debug(u'IpHandler._write_config_for_device: error flushing '
++                        u'-> %r', e)
+         try:
 -            call(self._render_config('ip_flush', dict(dev=device.name)), shell=True)
++            log.debug(u'IpHandler._write_config_for_device: flushing addrs...')
++            call(self._render_config('ip_flush', dict(dev=device.name)),
++                        shell=True)
+         except ExecutionError, e:
 -            print e
++            log.debug(u'IpHandler._write_config_for_device: error flushing '
++                        u'-> %r', e)
+         for address in device.addrs.values():
+             broadcast = address.broadcast
+             if broadcast is None:
+                 broadcast = '+'
+             try:
++                log.debug(u'IpHandler._write_config_for_device: adding %r',
++                            address)
+                 call(self._render_config('ip_add', dict(
+                     dev = device.name,
+                     addr = address.ip,
+                     netmask = address.netmask,
+                     peer = address.peer,
+                     broadcast = broadcast,
+                     )
+                 ), shell=True)
+             except ExecutionError, e:
 -                print e
++                log.debug(u'IpHandler._write_config_for_device: error adding '
++                            u'-> %r', e)
+         for route in device.routes:
+             try:
++                log.debug(u'IpHandler._write_config_for_device: adding %r',
++                            route)
+                 call(self._render_config('route_add', dict(
+                         dev = device.name,
+                         net_addr = route.net_addr,
+                         prefix = route.prefix,
+                         gateway = route.gateway,
+                     )
+                 ), shell=True)
+             except ExecutionError, e:
 -                print e
++                log.debug(u'IpHandler._write_config_for_device: error adding '
++                            u'-> %r', e)
  
      def handle_timer(self):
 +        log.debug(u'IpHandler.handle_timer()')
          self.refresh_devices()
  
 -
      def refresh_devices(self):
 +        log.debug(u'IpHandler.update_devices()')
          devices = get_network_devices()
-         #add not registered devices
+         #add not registered and active devices
+         go_active = False
          for k,v in devices.items():
              if k not in self.devices:
 +                log.debug(u'IpHandler.update_devices: adding %r', v)
                  self.devices[k] = v
-         #delete dead devices
+             elif not self.devices[k].active:
+                 self.active = True
+                 go_active = True
+                 self._write_config_for_device(self.devices[k])
+         if go_active:
+             self._write_hops()
+             self._bring_up_no_dev_routes()
+             self._restart_services()
+         #mark inactive devices
          for k in self.devices.keys():
+             go_down = False
              if k not in devices:
-                 del self.devices[k]
 +                log.debug(u'IpHandler.update_devices: removing %s', k)
+                 self.devices[k].active = False
+                 go_down = True
+             if go_down:
+                 self._bring_up_no_dev_routes()
+     def _restart_services(self):
+         for s in self.services:
+             if s._service_running:
+                 try:
+                      s.stop()
+                 except ExecutionError:
+                     pass
+                 try:
+                     s.start()
+                 except ExecutionError:
+                     pass
+       #hooks a service to the ip handler, so when
+       #a device is brought up one can restart the service
+       #that need to refresh their device list
+     def device_up_hook(self, serv):
+         if hasattr(serv, 'stop') and hasattr(serv, 'start'):
+             self.services.append(serv)
  
  
  
  if __name__ == '__main__':
  
 -    ip = IpHanlder()
 +    logging.basicConfig(
 +        level   = logging.DEBUG,
 +        format  = '%(asctime)s %(levelname)-8s %(message)s',
 +        datefmt = '%H:%M:%S',
 +    )
 +
 +    ip = IpHandler()
      print '----------------------'
      ip.hop.add('201.21.32.53','eth0')
      ip.hop.add('205.65.65.25','eth1')
diff --combined pymin/services/util.py
index 21afa63a15f8cbb362bdecacca531d4b51a81071,cb97815e2b1bf9892bbf7b1803de06240859350f..69864cf36c0949ada6ba4a55fed7ef6b8307a75a
@@@ -8,7 -8,6 +8,7 @@@ try
      import cPickle as pickle
  except ImportError:
      import pickle
 +import logging ; log = logging.getLogger('pymin.services.util')
  
  from pymin.dispatcher import Handler, handler, HandlerError, \
                                  CommandNotFoundError
@@@ -156,10 -155,11 +156,11 @@@ class Device(Sequence)
          self.name = name
          self.mac = mac
          self.ppp = ppp
+         self.active = True
          self.addrs = dict()
          self.routes = list()
      def as_tuple(self):
-         return (self.name, self.mac, self.addrs)
+         return (self.name, self.mac, self.active, self.addrs)
  
  
  
@@@ -210,16 -210,17 +211,16 @@@ def get_peers()
  def call(command, stdin=subprocess.PIPE, stdout=subprocess.PIPE,
              stderr=subprocess.PIPE, close_fds=True, universal_newlines=True,
              **kw):
 +    log.debug(u'call(%r)', command)
      if DEBUG:
 -        if not isinstance(command, basestring):
 -            command = ' '.join(command)
 -        print 'Executing command:', command
 +        log.debug(u'call: not really executing, DEBUG mode')
          return
      try:
 -        print 'Executing command:', command
 -        r = subprocess.check_call(command, stdin=stdin, stdout=stdout,
 +        subprocess.check_call(command, stdin=stdin, stdout=stdout,
                      stderr=stderr, close_fds=close_fds,
                      universal_newlines=universal_newlines, **kw)
      except Exception, e:
 +        log.debug(u'call: Execution error %r', e)
          raise ExecutionError(command, e)
  
  class Persistent:
  
      def _dump_attr(self, attrname):
          r"_dump_attr() -> None :: Dump a specific variable to a pickle file."
 +        fname = self._pickle_filename(attrname)
 +        attr = getattr(self, attrname)
 +        log.debug(u'Persistent._dump_attr(%r) -> file=%r, value=%r',
 +                attrname, fname, attr)
          f = file(self._pickle_filename(attrname), 'wb')
 -        pickle.dump(getattr(self, attrname), f, 2)
 +        pickle.dump(attr, f, 2)
          f.close()
  
      def _load_attr(self, attrname):
          r"_load_attr() -> object :: Load a specific pickle file."
 -        f = file(self._pickle_filename(attrname))
 -        setattr(self, attrname, pickle.load(f))
 +        fname = self._pickle_filename(attrname)
 +        f = file(fname)
 +        attr = pickle.load(f)
 +        log.debug(u'Persistent._load_attr(%r) -> file=%r, value=%r',
 +                attrname, fname, attr)
 +        setattr(self, attrname, attr)
          f.close()
  
      def _pickle_filename(self, name):
@@@ -336,27 -329,18 +337,27 @@@ class Restorable(Persistent)
  
      def _restore(self):
          r"_restore() -> bool :: Restore persistent data or create a default."
 +        log.debug(u'Restorable._restore()')
          try:
 +            log.debug(u'Restorable._restore: trying to load...')
              self._load()
 +            log.debug(u'Restorable._restore: load OK')
              return True
          except IOError:
 +            log.debug(u'Restorable._restore: load FAILED, making defaults: %r',
 +                        self._restorable_defaults)
              for (k, v) in self._restorable_defaults.items():
                  setattr(self, k, v)
              # TODO tener en cuenta servicios que hay que levantar y los que no
              if hasattr(self, 'commit'):
 +                log.debug(u'Restorable._restore: commit() found, commiting...')
                  self.commit()
                  return False
 +            log.debug(u'Restorable._restore: dumping new defaults...')
              self._dump()
              if hasattr(self, '_write_config'):
 +                log.debug(u'Restorable._restore: _write_config() found, '
 +                            u'writing new config...')
                  self._write_config()
              return False
  
@@@ -420,7 -404,6 +421,7 @@@ class ConfigWriter
  
      def _config_build_templates(self):
          r"_config_writer_templates() -> None :: Build the template objects."
 +        log.debug(u'ConfigWriter.build_templates()')
          if isinstance(self._config_writer_files, basestring):
              self._config_writer_files = (self._config_writer_files,)
          if not hasattr(self, '_config_writer_templates') \
                  vars = dict()
          elif callable(vars):
              vars = vars(template_name)
 +        log.debug(u'ConfigWriter._render_config: rendering template %r with '
 +                    u'vars=%r', template_name, vars)
          return self._config_writer_templates[template_name].render(**vars)
  
      def _get_config_path(self, template_name, config_filename=None):
                  vars = dict()
          elif callable(vars):
              vars = vars(template_name)
 -        f = file(self._get_config_path(template_name, config_filename), 'w')
 +        fname = self._get_config_path(template_name, config_filename)
 +        f = file(fname, 'w')
          ctx = Context(f, **vars)
 +        log.debug(u'ConfigWriter._write_single_config: rendering template '
 +                    u'%r with vars=%r to file %r', template_name, vars, fname)
          self._config_writer_templates[template_name].render_context(ctx)
          f.close()
  
@@@ -518,31 -496,23 +519,31 @@@ class ServiceHandler(Handler, Restorabl
  
      def __init__(self, start=None, stop=None, restart=None, reload=None):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'ServiceHandler(%r, %r, %r, %r)', start, stop, restart,
 +                    reload)
          for (name, action) in dict(start=start, stop=stop, restart=restart,
                                                      reload=reload).items():
              if action is not None:
 -                setattr(self, '_service_%s' % name, action)
 +                attr_name = '_service_%s' % name
 +                log.debug(u'ServiceHandler: using %r as %s', attr_name, action)
 +                setattr(self, attr_name, action)
          self._persistent_attrs = list(self._persistent_attrs)
          self._persistent_attrs.append('_service_running')
          if '_service_running' not in self._restorable_defaults:
              self._restorable_defaults['_service_running'] = False
 +        log.debug(u'ServiceHandler: restoring service configuration...')
          self._restore()
          if self._service_running:
 +            log.debug(u'ServiceHandler: service was running, starting it...')
              self._service_running = False
              self.start()
  
      @handler(u'Start the service.')
      def start(self):
          r"start() -> None :: Start the service."
 +        log.debug(u'ServiceHandler.start()')
          if not self._service_running:
 +            log.debug(u'ServiceHandler.start: not running, starting it...')
              if callable(self._service_start):
                  self._service_start()
              else:
  
      @handler(u'Stop the service.')
      def stop(self):
 +        log.debug(u'ServiceHandler.stop()')
          r"stop() -> None :: Stop the service."
          if self._service_running:
 +            log.debug(u'ServiceHandler.stop: running, stoping it...')
              if callable(self._service_stop):
                  self._service_stop()
              else:
      @handler(u'Restart the service.')
      def restart(self):
          r"restart() -> None :: Restart the service."
 +        log.debug(u'ServiceHandler.restart()')
          if callable(self._service_restart):
              self._service_restart()
          else:
      @handler(u'Reload the service config (without restarting, if possible).')
      def reload(self):
          r"reload() -> None :: Reload the configuration of the service."
 +        log.debug(u'ServiceHandler.reload()')
          if self._service_running:
 +            log.debug(u'ServiceHandler.reload: running, reloading...')
              if callable(self._service_reload):
                  self._service_reload()
              else:
      @handler(u'Tell if the service is running.')
      def running(self):
          r"reload() -> None :: Reload the configuration of the service."
 +        log.debug(u'ServiceHandler.running() -> %r', self._service_running)
          if self._service_running:
              return 1
          else:
@@@ -605,7 -569,6 +606,7 @@@ class RestartHandler(Handler)
      @handler(u'Restart the service (alias to stop + start).')
      def restart(self):
          r"restart() -> None :: Restart the service calling stop() and start()."
 +        log.debug(u'RestartHandler.restart()')
          self.stop()
          self.start()
  
@@@ -619,9 -582,7 +620,9 @@@ class ReloadHandler(Handler)
      @handler(u'Reload the service config (alias to restart).')
      def reload(self):
          r"reload() -> None :: Reload the configuration of the service."
 +        log.debug(u'ReloadHandler.reload()')
          if hasattr(self, '_service_running') and self._service_running:
 +            log.debug(u'ReloadHandler.reload: running, reloading...')
              self.restart()
  
  class InitdHandler(ServiceHandler):
  
      def __init__(self, initd_name=None, initd_dir=None):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'InitdHandler(%r, %r)', initd_name, initd_dir)
          if initd_name is not None:
              self._initd_name = initd_name
          if initd_dir is not None:
          ServiceHandler.__init__(self, **actions)
  
      def handle_timer(self):
 +        # TODO documentation
 +        log.debug(u'InitdHandler.handle_timer(): self=%r', self)
          p = subprocess.Popen(('pgrep', '-f', self._initd_name),
                                  stdout=subprocess.PIPE)
          pid = p.communicate()[0]
          if p.returncode == 0 and len(pid) > 0:
 +            log.debug(u'InitdHandler.handle_timer: pid present, running')
              self._service_running = True
          else:
 +            log.debug(u'InitdHandler.handle_timer: pid absent, NOT running')
              self._service_running = False
  
  class TransactionalHandler(Handler):
      @handler(u'Commit the changes (reloading the service, if necessary).')
      def commit(self):
          r"commit() -> None :: Commit the changes and reload the service."
 +        log.debug(u'TransactionalHandler.commit()')
          if hasattr(self, '_dump'):
 +            log.debug(u'TransactionalHandler.commit: _dump() present, '
 +                        u'dumping...')
              self._dump()
          unchanged = False
          if hasattr(self, '_write_config'):
 +            log.debug(u'TransactionalHandler.commit: _write_config() present, '
 +                        u'writing config...')
              unchanged = self._write_config()
          if not unchanged and hasattr(self, 'reload'):
 +            log.debug(u'TransactionalHandler.commit: reload() present, and'
 +                        u'configuration changed, reloading...')
              self.reload()
  
      @handler(u'Discard all the uncommited changes.')
      def rollback(self):
          r"rollback() -> None :: Discard the changes not yet commited."
 +        log.debug(u'TransactionalHandler.reload()')
          if hasattr(self, '_load'):
 +            log.debug(u'TransactionalHandler.reload: _load() present, loading'
 +                        u'pickled values...')
              self._load()
  
  class ParametersHandler(Handler):
  
      def __init__(self, attr=None):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'ParametersHandler(%r)', attr)
          if attr is not None:
              self._parameters_attr = attr
  
      @handler(u'Set a service parameter.')
      def set(self, param, value):
          r"set(param, value) -> None :: Set a service parameter."
 +        log.debug(u'ParametersHandler.set(%r, %r)', param, value)
          if not param in self.params:
 +            log.debug(u'ParametersHandler.set: parameter not found')
              raise ParameterNotFoundError(param)
          self.params[param] = value
          if hasattr(self, '_update'):
 +            log.debug(u'ParametersHandler.set: _update found, setting to True')
              self._update = True
  
      @handler(u'Get a service parameter.')
      def get(self, param):
          r"get(param) -> None :: Get a service parameter."
 +        log.debug(u'ParametersHandler.get(%r)', param)
          if not param in self.params:
 +            log.debug(u'ParametersHandler.get: parameter not found')
              raise ParameterNotFoundError(param)
          return self.params[param]
  
      @handler(u'List all available service parameters.')
      def list(self):
          r"list() -> tuple :: List all the parameter names."
 +        log.debug(u'ParametersHandler.list()')
          return self.params.keys()
  
      @handler(u'Get all service parameters, with their values.')
      def show(self):
          r"show() -> (key, value) tuples :: List all the parameters."
 +        log.debug(u'ParametersHandler.show()')
          return self.params.items()
  
  class SubHandler(Handler):
  
      def __init__(self, parent):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'SubHandler(%r)', parent)
          self.parent = parent
  
  class ContainerSubHandler(SubHandler):
  
      def __init__(self, parent, attr=None, cls=None):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'ContainerSubHandler(%r, %r, %r)', parent, attr, cls)
          self.parent = parent
          if attr is not None:
              self._cont_subhandler_attr = attr
      @handler(u'Add a new item')
      def add(self, *args, **kwargs):
          r"add(...) -> None :: Add an item to the list."
 +        log.debug(u'ContainerSubHandler.add(%r, %r)', args, kwargs)
          item = self._cont_subhandler_class(*args, **kwargs)
          if hasattr(item, '_add'):
 +            log.debug(u'ContainerSubHandler.add: _add found, setting to True')
              item._add = True
          key = item
          if isinstance(self._attr(), dict):
              key = item.as_tuple()[0]
          # do we have the same item? then raise an error
          if key in self._vattr():
 +            log.debug(u'ContainerSubHandler.add: allready exists')
              raise ItemAlreadyExistsError(item)
          # do we have the same item, but logically deleted? then update flags
          if key in self._attr():
 +            log.debug(u'ContainerSubHandler.add: was deleted, undeleting it')
              index = key
              if not isinstance(self._attr(), dict):
                  index = self._attr().index(item)
      @handler(u'Update an item')
      def update(self, index, *args, **kwargs):
          r"update(index, ...) -> None :: Update an item of the container."
 +        log.debug(u'ContainerSubHandler.update(%r, %r, %r)',
 +                    index, args, kwargs)
          # TODO make it right with metaclasses, so the method is not created
          # unless the update() method really exists.
 -        # TODO check if the modified item is the same of an existing one
          if not isinstance(self._attr(), dict):
              index = int(index) # TODO validation
          if not hasattr(self._cont_subhandler_class, 'update'):
 +            log.debug(u'ContainerSubHandler.update: update() not found, '
 +                        u"can't really update, raising command not found")
              raise CommandNotFoundError(('update',))
          try:
              item = self._vattr()[index]
              item.update(*args, **kwargs)
              if hasattr(item, '_update'):
 +                log.debug(u'ContainerSubHandler.update: _update found, '
 +                            u'setting to True')
                  item._update = True
          except LookupError:
 +            log.debug(u'ContainerSubHandler.update: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Delete an item')
      def delete(self, index):
          r"delete(index) -> None :: Delete an item of the container."
 +        log.debug(u'ContainerSubHandler.delete(%r)', index)
          if not isinstance(self._attr(), dict):
              index = int(index) # TODO validation
          try:
              item = self._vattr()[index]
              if hasattr(item, '_delete'):
 +                log.debug(u'ContainerSubHandler.delete: _delete found, '
 +                            u'setting to True')
                  item._delete = True
              else:
                  del self._attr()[index]
              return item
          except LookupError:
 +            log.debug(u'ContainerSubHandler.delete: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Remove all items (use with care).')
      def clear(self):
          r"clear() -> None :: Delete all items of the container."
 +        log.debug(u'ContainerSubHandler.clear()')
 +        # FIXME broken really, no _delete attribute is setted :S
          if isinstance(self._attr(), dict):
              self._attr.clear()
          else:
      @handler(u'Get information about an item')
      def get(self, index):
          r"get(index) -> item :: List all the information of an item."
 +        log.debug(u'ContainerSubHandler.get(%r)', index)
          if not isinstance(self._attr(), dict):
              index = int(index) # TODO validation
          try:
              return self._vattr()[index]
          except LookupError:
 +            log.debug(u'ContainerSubHandler.get: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Get information about all items')
      def show(self):
          r"show() -> list of items :: List all the complete items information."
 +        log.debug(u'ContainerSubHandler.show()')
          if isinstance(self._attr(), dict):
              return self._attr().values()
          return self._vattr()
@@@ -949,7 -866,6 +950,7 @@@ class ListSubHandler(ContainerSubHandle
      @handler(u'Get how many items are in the list')
      def len(self):
          r"len() -> int :: Get how many items are in the list."
 +        log.debug(u'ListContainerSubHandler.len()')
          return len(self._vattr())
  
  class DictSubHandler(ContainerSubHandler):
      @handler(u'List all the items by key')
      def list(self):
          r"list() -> tuple :: List all the item keys."
 +        log.debug(u'DictContainerSubHandler.list()')
          return self._attr().keys()
  
  class ComposedSubHandler(SubHandler):
  
      def __init__(self, parent, cont=None, attr=None, cls=None):
          r"Initialize the object, see the class documentation for details."
 +        log.debug(u'ComposedSubHandler(%r, %r, %r, %r)',
 +                    parent, cont, attr, cls)
          self.parent = parent
          if cont is not None:
              self._comp_subhandler_cont = cont
      @handler(u'Add a new item')
      def add(self, cont, *args, **kwargs):
          r"add(cont, ...) -> None :: Add an item to the list."
 +        log.debug(u'ComposedSubHandler.add(%r, %r, %r)', cont, args, kwargs)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          item = self._comp_subhandler_class(*args, **kwargs)
          if hasattr(item, '_add'):
 +            log.debug(u'ComposedSubHandler.add: _add found, setting to True')
              item._add = True
          key = item
          if isinstance(self._attr(cont), dict):
              key = item.as_tuple()[0]
          # do we have the same item? then raise an error
          if key in self._vattr(cont):
 +            log.debug(u'ComposedSubHandler.add: allready exists')
              raise ItemAlreadyExistsError(item)
          # do we have the same item, but logically deleted? then update flags
          if key in self._attr(cont):
 +            log.debug(u'ComposedSubHandler.add: was deleted, undeleting it')
              index = key
              if not isinstance(self._attr(cont), dict):
                  index = self._attr(cont).index(item)
              else:
                  self._attr(cont).append(item)
          if hasattr(self._cont()[cont], '_update'):
 +            log.debug(u"ComposedSubHandler.add: container's _update found, "
 +                        u'setting to True')
              self._cont()[cont]._update = True
  
      @handler(u'Update an item')
          r"update(cont, index, ...) -> None :: Update an item of the container."
          # TODO make it right with metaclasses, so the method is not created
          # unless the update() method really exists.
 -        # TODO check if the modified item is the same of an existing one
 +        log.debug(u'ComposedSubHandler.update(%r, %r, %r, %r)',
 +                    cont, index, args, kwargs)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          if not isinstance(self._attr(cont), dict):
              index = int(index) # TODO validation
          if not hasattr(self._comp_subhandler_class, 'update'):
 +            log.debug(u'ComposedSubHandler.update: update() not found, '
 +                        u"can't really update, raising command not found")
              raise CommandNotFoundError(('update',))
          try:
              item = self._vattr(cont)[index]
              item.update(*args, **kwargs)
              if hasattr(item, '_update'):
 +                log.debug(u'ComposedSubHandler.update: _update found, '
 +                            u'setting to True')
                  item._update = True
              if hasattr(self._cont()[cont], '_update'):
 +                log.debug(u"ComposedSubHandler.add: container's _update found, "
 +                            u'setting to True')
                  self._cont()[cont]._update = True
          except LookupError:
 +            log.debug(u'ComposedSubHandler.update: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Delete an item')
      def delete(self, cont, index):
          r"delete(cont, index) -> None :: Delete an item of the container."
 +        log.debug(u'ComposedSubHandler.delete(%r, %r)', cont, index)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          if not isinstance(self._attr(cont), dict):
              index = int(index) # TODO validation
          try:
              item = self._vattr(cont)[index]
              if hasattr(item, '_delete'):
 +                log.debug(u'ComposedSubHandler.delete: _delete found, '
 +                            u'setting to True')
                  item._delete = True
              else:
                  del self._attr(cont)[index]
              if hasattr(self._cont()[cont], '_update'):
 +                log.debug(u"ComposedSubHandler.add: container's _update found, "
 +                            u'setting to True')
                  self._cont()[cont]._update = True
              return item
          except LookupError:
 +            log.debug(u'ComposedSubHandler.delete: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Remove all items (use with care).')
      def clear(self, cont):
          r"clear(cont) -> None :: Delete all items of the container."
 +        # FIXME broken really, no item or container _delete attribute is
 +        #       setted :S
 +        log.debug(u'ComposedSubHandler.clear(%r)', cont)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          if isinstance(self._attr(cont), dict):
              self._attr(cont).clear()
      @handler(u'Get information about an item')
      def get(self, cont, index):
          r"get(cont, index) -> item :: List all the information of an item."
 +        log.debug(u'ComposedSubHandler.get(%r, %r)', cont, index)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          if not isinstance(self._attr(cont), dict):
              index = int(index) # TODO validation
          try:
              return self._vattr(cont)[index]
          except LookupError:
 +            log.debug(u'ComposedSubHandler.get: item not found')
              raise ItemNotFoundError(index)
  
      @handler(u'Get information about all items')
      def show(self, cont):
          r"show(cont) -> list of items :: List all the complete items information."
 +        log.debug(u'ComposedSubHandler.show(%r)', cont)
          if not cont in self._cont():
 +            log.debug(u'ComposedSubHandler.add: container not found')
              raise ContainerNotFoundError(cont)
          if isinstance(self._attr(cont), dict):
              return self._attr(cont).values()
@@@ -1176,7 -1057,6 +1177,7 @@@ class ListComposedSubHandler(ComposedSu
      @handler(u'Get how many items are in the list')
      def len(self, cont):
          r"len(cont) -> int :: Get how many items are in the list."
 +        log.debug(u'ListComposedSubHandler.len(%r)', cont)
          if not cont in self._cont():
              raise ContainerNotFoundError(cont)
          return len(self._vattr(cont))
@@@ -1191,7 -1071,6 +1192,7 @@@ class DictComposedSubHandler(ComposedSu
      @handler(u'List all the items by key')
      def list(self, cont):
          r"list(cont) -> tuple :: List all the item keys."
 +        log.debug(u'DictComposedSubHandler.list(%r)', cont)
          if not cont in self._cont():
              raise ContainerNotFoundError(cont)
          return self._attr(cont).keys()
  
  if __name__ == '__main__':
  
 +    logging.basicConfig(
 +        level   = logging.DEBUG,
 +        format  = '%(asctime)s %(levelname)-8s %(message)s',
 +        datefmt = '%H:%M:%S',
 +    )
 +
      import sys
  
      # Execution tests