rework logging connections

IPython/zmq/parallel/clusterdir.py

@@ -1,537 +1,536 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 The IPython cluster directory
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 from __future__ import with_statement
 
 import os
 import shutil
 import sys
 import logging
 import warnings
 
 from IPython.config.loader import PyFileConfigLoader
 from IPython.core.application import Application, BaseAppConfigLoader
 from IPython.config.configurable import Configurable
 from IPython.core.crashhandler import CrashHandler
 from IPython.core import release
 from IPython.utils.path import (
     get_ipython_package_dir,
     expand_path
 )
 from IPython.utils.traitlets import Unicode
 
 #-----------------------------------------------------------------------------
 # Module errors
 #-----------------------------------------------------------------------------
 
 class ClusterDirError(Exception):
     pass
 
 
 class PIDFileError(Exception):
     pass
 
 
 #-----------------------------------------------------------------------------
 # Class for managing cluster directories
 #-----------------------------------------------------------------------------
 
 class ClusterDir(Configurable):
     """An object to manage the cluster directory and its resources.
 
     The cluster directory is used by :command:`ipengine`, 
     :command:`ipcontroller` and :command:`ipclsuter` to manage the
     configuration, logging and security of these applications.
 
     This object knows how to find, create and manage these directories. This
     should be used by any code that want's to handle cluster directories.
     """
 
     security_dir_name = Unicode('security')
     log_dir_name = Unicode('log')
     pid_dir_name = Unicode('pid')
     security_dir = Unicode(u'')
     log_dir = Unicode(u'')
     pid_dir = Unicode(u'')
     location = Unicode(u'')
 
     def __init__(self, location=u''):
         super(ClusterDir, self).__init__(location=location)
 
     def _location_changed(self, name, old, new):
         if not os.path.isdir(new):
             os.makedirs(new)
         self.security_dir = os.path.join(new, self.security_dir_name)
         self.log_dir = os.path.join(new, self.log_dir_name)
         self.pid_dir = os.path.join(new, self.pid_dir_name)
         self.check_dirs()
 
     def _log_dir_changed(self, name, old, new):
         self.check_log_dir()
 
     def check_log_dir(self):
         if not os.path.isdir(self.log_dir):
             os.mkdir(self.log_dir)
 
     def _security_dir_changed(self, name, old, new):
         self.check_security_dir()
 
     def check_security_dir(self):
         if not os.path.isdir(self.security_dir):
             os.mkdir(self.security_dir, 0700)
         os.chmod(self.security_dir, 0700)
 
     def _pid_dir_changed(self, name, old, new):
         self.check_pid_dir()
 
     def check_pid_dir(self):
         if not os.path.isdir(self.pid_dir):
             os.mkdir(self.pid_dir, 0700)
         os.chmod(self.pid_dir, 0700)
 
     def check_dirs(self):
         self.check_security_dir()
         self.check_log_dir()
         self.check_pid_dir()
 
     def load_config_file(self, filename):
         """Load a config file from the top level of the cluster dir.
 
         Parameters
         ----------
         filename : unicode or str
             The filename only of the config file that must be located in
             the top-level of the cluster directory.
         """
         loader = PyFileConfigLoader(filename, self.location)
         return loader.load_config()
 
     def copy_config_file(self, config_file, path=None, overwrite=False):
         """Copy a default config file into the active cluster directory.
 
         Default configuration files are kept in :mod:`IPython.config.default`.
         This function moves these from that location to the working cluster
         directory.
         """
         if path is None:
             import IPython.config.default
             path = IPython.config.default.__file__.split(os.path.sep)[:-1]
             path = os.path.sep.join(path)
         src = os.path.join(path, config_file)
         dst = os.path.join(self.location, config_file)
         if not os.path.isfile(dst) or overwrite:
             shutil.copy(src, dst)
 
     def copy_all_config_files(self, path=None, overwrite=False):
         """Copy all config files into the active cluster directory."""
         for f in [u'ipcontroller_config.py', u'ipengine_config.py',
                   u'ipcluster_config.py']:
             self.copy_config_file(f, path=path, overwrite=overwrite)
 
     @classmethod
     def create_cluster_dir(csl, cluster_dir):
         """Create a new cluster directory given a full path.
 
         Parameters
         ----------
         cluster_dir : str
             The full path to the cluster directory.  If it does exist, it will
             be used.  If not, it will be created.
         """
         return ClusterDir(location=cluster_dir)
 
     @classmethod
     def create_cluster_dir_by_profile(cls, path, profile=u'default'):
         """Create a cluster dir by profile name and path.
 
         Parameters
         ----------
         path : str
             The path (directory) to put the cluster directory in.
         profile : str
             The name of the profile.  The name of the cluster directory will
             be "clusterz_<profile>".
         """
         if not os.path.isdir(path):
             raise ClusterDirError('Directory not found: %s' % path)
         cluster_dir = os.path.join(path, u'clusterz_' + profile)
         return ClusterDir(location=cluster_dir)
 
     @classmethod
     def find_cluster_dir_by_profile(cls, ipython_dir, profile=u'default'):
         """Find an existing cluster dir by profile name, return its ClusterDir.
 
         This searches through a sequence of paths for a cluster dir.  If it
         is not found, a :class:`ClusterDirError` exception will be raised.
 
         The search path algorithm is:
         1. ``os.getcwd()``
         2. ``ipython_dir``
         3. The directories found in the ":" separated 
            :env:`IPCLUSTER_DIR_PATH` environment variable.
 
         Parameters
         ----------
         ipython_dir : unicode or str
             The IPython directory to use.
         profile : unicode or str
             The name of the profile.  The name of the cluster directory
             will be "clusterz_<profile>".
         """
         dirname = u'clusterz_' + profile
         cluster_dir_paths = os.environ.get('IPCLUSTER_DIR_PATH','')
         if cluster_dir_paths:
             cluster_dir_paths = cluster_dir_paths.split(':')
         else:
             cluster_dir_paths = []
         paths = [os.getcwd(), ipython_dir] + cluster_dir_paths
         for p in paths:
             cluster_dir = os.path.join(p, dirname)
             if os.path.isdir(cluster_dir):
                 return ClusterDir(location=cluster_dir)
         else:
             raise ClusterDirError('Cluster directory not found in paths: %s' % dirname)
 
     @classmethod
     def find_cluster_dir(cls, cluster_dir):
         """Find/create a cluster dir and return its ClusterDir.
 
         This will create the cluster directory if it doesn't exist.
 
         Parameters
         ----------
         cluster_dir : unicode or str
             The path of the cluster directory.  This is expanded using
             :func:`IPython.utils.genutils.expand_path`.
         """
         cluster_dir = expand_path(cluster_dir)
         if not os.path.isdir(cluster_dir):
             raise ClusterDirError('Cluster directory not found: %s' % cluster_dir)
         return ClusterDir(location=cluster_dir)
 
 
 #-----------------------------------------------------------------------------
 # Command line options
 #-----------------------------------------------------------------------------
 
 class ClusterDirConfigLoader(BaseAppConfigLoader):
 
     def _add_cluster_profile(self, parser):
         paa = parser.add_argument
         paa('-p', '--profile',
             dest='Global.profile',type=unicode,
             help=
             """The string name of the profile to be used. This determines the name
             of the cluster dir as: cluster_<profile>. The default profile is named
             'default'.  The cluster directory is resolve this way if the
             --cluster-dir option is not used.""",
             metavar='Global.profile')
 
     def _add_cluster_dir(self, parser):
         paa = parser.add_argument
         paa('--cluster-dir',
             dest='Global.cluster_dir',type=unicode,
             help="""Set the cluster dir. This overrides the logic used by the
             --profile option.""",
             metavar='Global.cluster_dir')
 
     def _add_work_dir(self, parser):
         paa = parser.add_argument
         paa('--work-dir',
             dest='Global.work_dir',type=unicode,
             help='Set the working dir for the process.',
             metavar='Global.work_dir')
 
     def _add_clean_logs(self, parser):
         paa = parser.add_argument
         paa('--clean-logs',
             dest='Global.clean_logs', action='store_true',
             help='Delete old log flies before starting.')
 
     def _add_no_clean_logs(self, parser):
         paa = parser.add_argument
         paa('--no-clean-logs',
             dest='Global.clean_logs', action='store_false',
             help="Don't Delete old log flies before starting.")
 
     def _add_arguments(self):
         super(ClusterDirConfigLoader, self)._add_arguments()
         self._add_cluster_profile(self.parser)
         self._add_cluster_dir(self.parser)
         self._add_work_dir(self.parser)
         self._add_clean_logs(self.parser)
         self._add_no_clean_logs(self.parser)
 
 
 #-----------------------------------------------------------------------------
 # Crash handler for this application
 #-----------------------------------------------------------------------------
 
 
 _message_template = """\
 Oops, $self.app_name crashed. We do our best to make it stable, but...
 
 A crash report was automatically generated with the following information:
   - A verbatim copy of the crash traceback.
   - Data on your current $self.app_name configuration.
 
 It was left in the file named:
 \t'$self.crash_report_fname'
 If you can email this file to the developers, the information in it will help
 them in understanding and correcting the problem.
 
 You can mail it to: $self.contact_name at $self.contact_email
 with the subject '$self.app_name Crash Report'.
 
 If you want to do it now, the following command will work (under Unix):
 mail -s '$self.app_name Crash Report' $self.contact_email < $self.crash_report_fname
 
 To ensure accurate tracking of this issue, please file a report about it at:
 $self.bug_tracker
 """
 
 class ClusterDirCrashHandler(CrashHandler):
     """sys.excepthook for IPython itself, leaves a detailed report on disk."""
 
     message_template = _message_template
 
     def __init__(self, app):
         contact_name = release.authors['Brian'][0]
         contact_email = release.authors['Brian'][1]
         bug_tracker = 'http://github.com/ipython/ipython/issues'
         super(ClusterDirCrashHandler,self).__init__(
             app, contact_name, contact_email, bug_tracker
         )
 
 
 #-----------------------------------------------------------------------------
 # Main application
 #-----------------------------------------------------------------------------
 
 class ApplicationWithClusterDir(Application):
     """An application that puts everything into a cluster directory.
 
     Instead of looking for things in the ipython_dir, this type of application
     will use its own private directory called the "cluster directory"
     for things like config files, log files, etc.
 
     The cluster directory is resolved as follows:
 
     * If the ``--cluster-dir`` option is given, it is used.
     * If ``--cluster-dir`` is not given, the application directory is 
       resolve using the profile name as ``cluster_<profile>``. The search 
       path for this directory is then i) cwd if it is found there
       and ii) in ipython_dir otherwise.
 
     The config file for the application is to be put in the cluster
     dir and named the value of the ``config_file_name`` class attribute.
     """
 
     command_line_loader = ClusterDirConfigLoader
     crash_handler_class = ClusterDirCrashHandler
     auto_create_cluster_dir = True
     # temporarily override default_log_level to DEBUG
     default_log_level = logging.DEBUG
 
     def create_default_config(self):
         super(ApplicationWithClusterDir, self).create_default_config()
         self.default_config.Global.profile = u'default'
         self.default_config.Global.cluster_dir = u''
         self.default_config.Global.work_dir = os.getcwd()
         self.default_config.Global.log_to_file = False
         self.default_config.Global.log_url = None
         self.default_config.Global.clean_logs = False
 
     def find_resources(self):
         """This resolves the cluster directory.
 
         This tries to find the cluster directory and if successful, it will
         have done:
         * Sets ``self.cluster_dir_obj`` to the :class:`ClusterDir` object for 
           the application.
         * Sets ``self.cluster_dir`` attribute of the application and config
           objects.
 
         The algorithm used for this is as follows:
         1. Try ``Global.cluster_dir``.
         2. Try using ``Global.profile``.
         3. If both of these fail and ``self.auto_create_cluster_dir`` is
            ``True``, then create the new cluster dir in the IPython directory.
         4. If all fails, then raise :class:`ClusterDirError`.
         """
 
         try:
             cluster_dir = self.command_line_config.Global.cluster_dir
         except AttributeError:
             cluster_dir = self.default_config.Global.cluster_dir
         cluster_dir = expand_path(cluster_dir)
         try:
             self.cluster_dir_obj = ClusterDir.find_cluster_dir(cluster_dir)
         except ClusterDirError:
             pass
         else:
             self.log.info('Using existing cluster dir: %s' % \
                 self.cluster_dir_obj.location
             )
             self.finish_cluster_dir()
             return
 
         try:
             self.profile = self.command_line_config.Global.profile
         except AttributeError:
             self.profile = self.default_config.Global.profile
         try:
             self.cluster_dir_obj = ClusterDir.find_cluster_dir_by_profile(
                 self.ipython_dir, self.profile)
         except ClusterDirError:
             pass
         else:
             self.log.info('Using existing cluster dir: %s' % \
                 self.cluster_dir_obj.location
             )
             self.finish_cluster_dir()
             return
 
         if self.auto_create_cluster_dir:
             self.cluster_dir_obj = ClusterDir.create_cluster_dir_by_profile(
                 self.ipython_dir, self.profile
             )
             self.log.info('Creating new cluster dir: %s' % \
                 self.cluster_dir_obj.location
             )
             self.finish_cluster_dir()
         else:
             raise ClusterDirError('Could not find a valid cluster directory.')
 
     def finish_cluster_dir(self):
         # Set the cluster directory
         self.cluster_dir = self.cluster_dir_obj.location
         
         # These have to be set because they could be different from the one
         # that we just computed.  Because command line has the highest
         # priority, this will always end up in the master_config.
         self.default_config.Global.cluster_dir = self.cluster_dir
         self.command_line_config.Global.cluster_dir = self.cluster_dir
 
     def find_config_file_name(self):
         """Find the config file name for this application."""
         # For this type of Application it should be set as a class attribute.
         if not hasattr(self, 'default_config_file_name'):
             self.log.critical("No config filename found")
         else:
             self.config_file_name = self.default_config_file_name
 
     def find_config_file_paths(self):
         # Set the search path to to the cluster directory. We should NOT
         # include IPython.config.default here as the default config files
         # are ALWAYS automatically moved to the cluster directory.
         conf_dir = os.path.join(get_ipython_package_dir(), 'config', 'default')
         self.config_file_paths = (self.cluster_dir,)
 
     def pre_construct(self):
         # The log and security dirs were set earlier, but here we put them
         # into the config and log them.
         config = self.master_config
         sdir = self.cluster_dir_obj.security_dir
         self.security_dir = config.Global.security_dir = sdir
         ldir = self.cluster_dir_obj.log_dir
         self.log_dir = config.Global.log_dir = ldir
         pdir = self.cluster_dir_obj.pid_dir
         self.pid_dir = config.Global.pid_dir = pdir
         self.log.info("Cluster directory set to: %s" % self.cluster_dir)
         config.Global.work_dir = unicode(expand_path(config.Global.work_dir))
         # Change to the working directory. We do this just before construct
         # is called so all the components there have the right working dir.
         self.to_work_dir()
 
     def to_work_dir(self):
         wd = self.master_config.Global.work_dir
         if unicode(wd) != unicode(os.getcwd()):
             os.chdir(wd)
             self.log.info("Changing to working dir: %s" % wd)
 
     def start_logging(self):
         # Remove old log files
         if self.master_config.Global.clean_logs:
             log_dir = self.master_config.Global.log_dir
             for f in os.listdir(log_dir):
                 if f.startswith(self.name + u'-') and f.endswith('.log'):
                     os.remove(os.path.join(log_dir, f))
         # Start logging to the new log file
         if self.master_config.Global.log_to_file:
             log_filename = self.name + u'-' + str(os.getpid()) + u'.log'
             logfile = os.path.join(self.log_dir, log_filename)
             open_log_file = open(logfile, 'w')
         elif self.master_config.Global.log_url:
             open_log_file = None
         else:
             open_log_file = sys.stdout
-        logger = logging.getLogger()
-        level = self.log_level
-        self.log = logger
-        # since we've reconnected the logger, we need to reconnect the log-level
-        self.log_level = level
-        if open_log_file is not None and self._log_handler not in self.log.handlers:
+        if open_log_file is not None:
+            self.log.removeHandler(self._log_handler)
+            self._log_handler = logging.StreamHandler(open_log_file)
+            self._log_formatter = logging.Formatter("[%(name)s] %(message)s")
+            self._log_handler.setFormatter(self._log_formatter)
             self.log.addHandler(self._log_handler)
         # log.startLogging(open_log_file)
 
     def write_pid_file(self, overwrite=False):
         """Create a .pid file in the pid_dir with my pid.
 
         This must be called after pre_construct, which sets `self.pid_dir`.
         This raises :exc:`PIDFileError` if the pid file exists already.
         """
         pid_file = os.path.join(self.pid_dir, self.name + u'.pid')
         if os.path.isfile(pid_file):
             pid = self.get_pid_from_file()
             if not overwrite:
                 raise PIDFileError(
                     'The pid file [%s] already exists. \nThis could mean that this '
                     'server is already running with [pid=%s].' % (pid_file, pid)
                 )
         with open(pid_file, 'w') as f:
             self.log.info("Creating pid file: %s" % pid_file)
             f.write(repr(os.getpid())+'\n')
 
     def remove_pid_file(self):
         """Remove the pid file.
 
         This should be called at shutdown by registering a callback with
         :func:`reactor.addSystemEventTrigger`. This needs to return
         ``None``.
         """
         pid_file = os.path.join(self.pid_dir, self.name + u'.pid')
         if os.path.isfile(pid_file):
             try:
                 self.log.info("Removing pid file: %s" % pid_file)
                 os.remove(pid_file)
             except:
                 self.log.warn("Error removing the pid file: %s" % pid_file)
 
     def get_pid_from_file(self):
         """Get the pid from the pid file.
 
         If the  pid file doesn't exist a :exc:`PIDFileError` is raised.
         """
         pid_file = os.path.join(self.pid_dir, self.name + u'.pid')
         if os.path.isfile(pid_file):
             with open(pid_file, 'r') as f:
                 pid = int(f.read().strip())
                 return pid
         else:
             raise PIDFileError('pid file not found: %s' % pid_file)
 

IPython/zmq/parallel/controller.py

@@ -1,110 +1,108 b''
 #!/usr/bin/env python
 """The IPython Controller with 0MQ
 This is a collection of one Hub and several Schedulers.
 """
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2010  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 from __future__ import print_function
 
 import logging
 from multiprocessing import Process
 
 import zmq
 
 # internal:
 from IPython.utils.importstring import import_item
 from IPython.utils.traitlets import Int, Str, Instance, List, Bool
 
 from entry_point import signal_children
 
 
 from scheduler import launch_scheduler
 from hub import Hub, HubFactory
 
 #-----------------------------------------------------------------------------
 # Configurable
 #-----------------------------------------------------------------------------
 
 
 class ControllerFactory(HubFactory):
     """Configurable for setting up a Hub and Schedulers."""
     
     scheme = Str('pure', config=True)
     usethreads = Bool(False, config=True)
     
     # internal
     children = List()
     mq_class = Str('zmq.devices.ProcessMonitoredQueue')
     
-    def _update_mq(self):
-        self.mq_class = 'zmq.devices.%sMonitoredQueue'%('Thread' if self.usethreads else 'Process')
+    def _usethreads_changed(self, name, old, new):
+        self.mq_class = 'zmq.devices.%sMonitoredQueue'%('Thread' if new else 'Process')
         
     def __init__(self, **kwargs):
         super(ControllerFactory, self).__init__(**kwargs)
         self.subconstructors.append(self.construct_schedulers)
-        self._update_mq()
-        self.on_trait_change(self._update_mq, 'usethreads')
     
     def start(self):
         super(ControllerFactory, self).start()
         for child in self.children:
             child.start()
         if not self.usethreads:
             signal_children([ getattr(c, 'launcher', c) for c in self.children ])
         
     
     def construct_schedulers(self):
         children = self.children
         mq = import_item(self.mq_class)
         
         # IOPub relay (in a Process)
         q = mq(zmq.PUB, zmq.SUB, zmq.PUB, 'N/A','iopub')
         q.bind_in(self.client_addrs['iopub'])
         q.bind_out(self.engine_addrs['iopub'])
         q.setsockopt_out(zmq.SUBSCRIBE, '')
         q.connect_mon(self.monitor_url)
         q.daemon=True
         children.append(q)
 
         # Multiplexer Queue (in a Process)
         q = mq(zmq.XREP, zmq.XREP, zmq.PUB, 'in', 'out')
         q.bind_in(self.client_addrs['mux'])
         q.bind_out(self.engine_addrs['mux'])
         q.connect_mon(self.monitor_url)
         q.daemon=True
         children.append(q)
 
         # Control Queue (in a Process)
         q = mq(zmq.XREP, zmq.XREP, zmq.PUB, 'incontrol', 'outcontrol')
         q.bind_in(self.client_addrs['control'])
         q.bind_out(self.engine_addrs['control'])
         q.connect_mon(self.monitor_url)
         q.daemon=True
         children.append(q)
         # Task Queue (in a Process)
         if self.scheme == 'pure':
-            logging.warn("task::using pure XREQ Task scheduler")
+            self.log.warn("task::using pure XREQ Task scheduler")
             q = mq(zmq.XREP, zmq.XREQ, zmq.PUB, 'intask', 'outtask')
             q.bind_in(self.client_addrs['task'])
             q.bind_out(self.engine_addrs['task'])
             q.connect_mon(self.monitor_url)
             q.daemon=True
             children.append(q)
         elif self.scheme == 'none':
-            logging.warn("task::using no Task scheduler")
+            self.log.warn("task::using no Task scheduler")
             
         else:
-            logging.warn("task::using Python %s Task scheduler"%self.scheme)
+            self.log.warn("task::using Python %s Task scheduler"%self.scheme)
             sargs = (self.client_addrs['task'], self.engine_addrs['task'], self.monitor_url, self.client_addrs['notification'])
             q = Process(target=launch_scheduler, args=sargs, kwargs = dict(scheme=self.scheme))
             q.daemon=True
             children.append(q)
 

IPython/zmq/parallel/engine.py

@@ -1,141 +1,140 b''
 #!/usr/bin/env python
 """A simple engine that talks to a controller over 0MQ.
 it handles registration, etc. and launches a kernel
 connected to the Controller's queue(s).
 """
 from __future__ import print_function
 import sys
 import time
 import uuid
 import logging
 from pprint import pprint
 
 import zmq
 from zmq.eventloop import ioloop, zmqstream
 
 # internal
 from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import Instance, Str, Dict, Int, Type
 # from IPython.utils.localinterfaces import LOCALHOST 
 
 from factory import RegistrationFactory
 
 from streamsession import Message
 from streamkernel import Kernel
 import heartmonitor
 
 def printer(*msg):
-    # print (logging.handlers, file=sys.__stdout__)
-    logging.info(str(msg))
+    # print (self.log.handlers, file=sys.__stdout__)
+    self.log.info(str(msg))
 
 class EngineFactory(RegistrationFactory):
     """IPython engine"""
     
     # configurables:
     user_ns=Dict(config=True)
     out_stream_factory=Type('IPython.zmq.iostream.OutStream', config=True)
     display_hook_factory=Type('IPython.zmq.displayhook.DisplayHook', config=True)
     
     # not configurable:
     id=Int(allow_none=True)
     registrar=Instance('zmq.eventloop.zmqstream.ZMQStream')
     kernel=Instance(Kernel)
     
     
     def __init__(self, **kwargs):
         super(EngineFactory, self).__init__(**kwargs)
         ctx = self.context
         
         reg = ctx.socket(zmq.PAIR)
         reg.setsockopt(zmq.IDENTITY, self.ident)
         reg.connect(self.url)
         self.registrar = zmqstream.ZMQStream(reg, self.loop)
         
     def register(self):
         """send the registration_request"""
         
-        logging.info("registering")
+        self.log.info("registering")
         content = dict(queue=self.ident, heartbeat=self.ident, control=self.ident)
         self.registrar.on_recv(self.complete_registration)
         # print (self.session.key)
         self.session.send(self.registrar, "registration_request",content=content)
     
     def complete_registration(self, msg):
         # print msg
         ctx = self.context
         loop = self.loop
         identity = self.ident
         print (identity)
         
         idents,msg = self.session.feed_identities(msg)
         msg = Message(self.session.unpack_message(msg))
         
         if msg.content.status == 'ok':
             self.id = int(msg.content.id)
             
             # create Shell Streams (MUX, Task, etc.):
             queue_addr = msg.content.mux
             shell_addrs = [ str(queue_addr) ]
             task_addr = msg.content.task
             if task_addr:
                 shell_addrs.append(str(task_addr))
             shell_streams = []
             for addr in shell_addrs:
                 stream = zmqstream.ZMQStream(ctx.socket(zmq.PAIR), loop)
                 stream.setsockopt(zmq.IDENTITY, identity)
                 stream.connect(addr)
                 shell_streams.append(stream)
             
             # control stream:
             control_addr = str(msg.content.control)
             control_stream = zmqstream.ZMQStream(ctx.socket(zmq.PAIR), loop)
             control_stream.setsockopt(zmq.IDENTITY, identity)
             control_stream.connect(control_addr)
             
             # create iopub stream:
             iopub_addr = msg.content.iopub
             iopub_stream = zmqstream.ZMQStream(ctx.socket(zmq.PUB), loop)
             iopub_stream.setsockopt(zmq.IDENTITY, identity)
             iopub_stream.connect(iopub_addr)
             
             # launch heartbeat
             hb_addrs = msg.content.heartbeat
             # print (hb_addrs)
             
             # # Redirect input streams and set a display hook.
             if self.out_stream_factory:
                 sys.stdout = self.out_stream_factory(self.session, iopub_stream, u'stdout')
                 sys.stdout.topic = 'engine.%i.stdout'%self.id
                 sys.stderr = self.out_stream_factory(self.session, iopub_stream, u'stderr')
                 sys.stderr.topic = 'engine.%i.stderr'%self.id
             if self.display_hook_factory:
                 sys.displayhook = self.display_hook_factory(self.session, iopub_stream)
                 sys.displayhook.topic = 'engine.%i.pyout'%self.id
             
-            self.kernel = Kernel(int_id=self.id, ident=self.ident, session=self.session, 
-                    control_stream=control_stream,
-                    shell_streams=shell_streams, iopub_stream=iopub_stream, loop=loop,
-                    user_ns = self.user_ns, config=self.config)
+            self.kernel = Kernel(config=self.config, int_id=self.id, ident=self.ident, session=self.session, 
+                    control_stream=control_stream, shell_streams=shell_streams, iopub_stream=iopub_stream, 
+                    loop=loop, user_ns = self.user_ns, logname=self.log.name)
             self.kernel.start()
             
             heart = heartmonitor.Heart(*map(str, hb_addrs), heart_id=identity)
             # ioloop.DelayedCallback(heart.start, 1000, self.loop).start()
             heart.start()
             
             
         else:
-            logging.error("Registration Failed: %s"%msg)
+            self.log.error("Registration Failed: %s"%msg)
             raise Exception("Registration Failed: %s"%msg)
         
-        logging.info("Completed registration with id %i"%self.id)
+        self.log.info("Completed registration with id %i"%self.id)
     
     
     def unregister(self):
         self.session.send(self.registrar, "unregistration_request", content=dict(id=self.id))
         time.sleep(1)
         sys.exit(0)
     
     def start(self):
         dc = ioloop.DelayedCallback(self.register, 0, self.loop)
         dc.start()
 

IPython/zmq/parallel/entry_point.py

@@ -1,118 +1,118 b''
 """ Defines helper functions for creating kernel entry points and process
 launchers.
 
 ************
 NOTE: Most of this module has been deprecated by moving to Configurables
 ************
 """
 
 # Standard library imports.
 import logging
 import atexit
 import sys
 import os
 import stat
 import socket
 from subprocess import Popen, PIPE
 from signal import signal, SIGINT, SIGABRT, SIGTERM
 try:
     from signal import SIGKILL
 except ImportError:
     SIGKILL=None
 
 # System library imports.
 import zmq
 from zmq.log import handlers
 # Local imports.
 from IPython.core.ultratb import FormattedTB
 from IPython.external.argparse import ArgumentParser
 from IPython.zmq.log import EnginePUBHandler
 
 _random_ports = set()
 
 def select_random_ports(n):
     """Selects and return n random ports that are available."""
     ports = []
     for i in xrange(n):
         sock = socket.socket()
         sock.bind(('', 0))
         while sock.getsockname()[1] in _random_ports:
             sock.close()
             sock = socket.socket()
             sock.bind(('', 0))
         ports.append(sock)
     for i, sock in enumerate(ports):
         port = sock.getsockname()[1]
         sock.close()
         ports[i] = port
         _random_ports.add(port)
     return ports
 
 def signal_children(children):
     """Relay interupt/term signals to children, for more solid process cleanup."""
     def terminate_children(sig, frame):
         logging.critical("Got signal %i, terminating children..."%sig)
         for child in children:
             child.terminate()
         
         sys.exit(sig != SIGINT)
         # sys.exit(sig)
     for sig in (SIGINT, SIGABRT, SIGTERM):
         signal(sig, terminate_children)
 
 def generate_exec_key(keyfile):
     import uuid
     newkey = str(uuid.uuid4())
     with open(keyfile, 'w') as f:
         # f.write('ipython-key ')
         f.write(newkey+'\n')
     # set user-only RW permissions (0600)
     # this will have no effect on Windows
     os.chmod(keyfile, stat.S_IRUSR|stat.S_IWUSR)
 
 
 def integer_loglevel(loglevel):
     try:
         loglevel = int(loglevel)
     except ValueError:
         if isinstance(loglevel, str):
             loglevel = getattr(logging, loglevel)
     return loglevel
 
-def connect_logger(context, iface, root="ip", loglevel=logging.DEBUG):
-    logger = logging.getLogger()
+def connect_logger(logname, context, iface, root="ip", loglevel=logging.DEBUG):
+    logger = logging.getLogger(logname)
     if any([isinstance(h, handlers.PUBHandler) for h in logger.handlers]):
         # don't add a second PUBHandler
         return
     loglevel = integer_loglevel(loglevel)
     lsock = context.socket(zmq.PUB)
     lsock.connect(iface)
     handler = handlers.PUBHandler(lsock)
     handler.setLevel(loglevel)
     handler.root_topic = root
     logger.addHandler(handler)
     logger.setLevel(loglevel)
 
 def connect_engine_logger(context, iface, engine, loglevel=logging.DEBUG):
     logger = logging.getLogger()
     if any([isinstance(h, handlers.PUBHandler) for h in logger.handlers]):
         # don't add a second PUBHandler
         return
     loglevel = integer_loglevel(loglevel)
     lsock = context.socket(zmq.PUB)
     lsock.connect(iface)
     handler = EnginePUBHandler(engine, lsock)
     handler.setLevel(loglevel)
     logger.addHandler(handler)
     logger.setLevel(loglevel)
 
-def local_logger(loglevel=logging.DEBUG):
+def local_logger(logname, loglevel=logging.DEBUG):
     loglevel = integer_loglevel(loglevel)
-    logger = logging.getLogger()
+    logger = logging.getLogger(logname)
     if any([isinstance(h, logging.StreamHandler) for h in logger.handlers]):
         # don't add a second StreamHandler
         return
     handler = logging.StreamHandler()
     handler.setLevel(loglevel)
     logger.addHandler(handler)
     logger.setLevel(loglevel)

IPython/zmq/parallel/factory.py

@@ -1,149 +1,155 b''
 """Base config factories."""
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 
 import os
 import logging
 
 import uuid
 
 from zmq.eventloop.ioloop import IOLoop
 
 from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import Str,Int,Instance, CUnicode, CStr
 from IPython.utils.importstring import import_item
 
 from IPython.zmq.parallel.entry_point import select_random_ports
 import IPython.zmq.parallel.streamsession as ss
 
 #-----------------------------------------------------------------------------
 # Classes
 #-----------------------------------------------------------------------------
+class LoggingFactory(Configurable):
+    """A most basic class, that has a `log` (type:`Logger`) attribute, set via a `logname` Trait."""
+    log = Instance('logging.Logger', ('ZMQ', logging.WARN))
+    logname = CStr('ZMQ')
+    def _logname_changed(self, name, old, new):
+        self.log = logging.getLogger(new)
+    
 
-
-class SessionFactory(Configurable):
+class SessionFactory(LoggingFactory):
     """The Base factory from which every factory in IPython.zmq.parallel inherits"""
     
     packer = Str('',config=True)
     unpacker = Str('',config=True)
     ident = CStr('',config=True)
     def _ident_default(self):
         return str(uuid.uuid4())
     username = Str(os.environ.get('USER','username'),config=True)
     exec_key = CUnicode('',config=True)
-    
     # not configurable:
     context = Instance('zmq.Context', (), {})
     session = Instance('IPython.zmq.parallel.streamsession.StreamSession')
-    loop = Instance('zmq.eventloop.ioloop.IOLoop')
+    loop = Instance('zmq.eventloop.ioloop.IOLoop', allow_none=False)
     def _loop_default(self):
         return IOLoop.instance()
     
+    
     def __init__(self, **kwargs):
         super(SessionFactory, self).__init__(**kwargs)
         
         keyfile = self.exec_key or None
         
         # set the packers:
         if not self.packer:
             packer_f = unpacker_f = None
         elif self.packer.lower() == 'json':
             packer_f = ss.json_packer
             unpacker_f = ss.json_unpacker
         elif self.packer.lower() == 'pickle':
             packer_f = ss.pickle_packer
             unpacker_f = ss.pickle_unpacker
         else:
             packer_f = import_item(self.packer)
             unpacker_f = import_item(self.unpacker)
         
         # construct the session
         self.session = ss.StreamSession(self.username, self.ident, packer=packer_f, unpacker=unpacker_f, keyfile=keyfile)
     
 
 class RegistrationFactory(SessionFactory):
     """The Base Configurable for objects that involve registration."""
     
     url = Str('', config=True) # url takes precedence over ip,regport,transport
     transport = Str('tcp', config=True)
     ip = Str('127.0.0.1', config=True)
     regport = Instance(int, config=True)
     def _regport_default(self):
         return 10101
         # return select_random_ports(1)[0]
     
     def __init__(self, **kwargs):
         super(RegistrationFactory, self).__init__(**kwargs)
         self._propagate_url()
         self._rebuild_url()
         self.on_trait_change(self._propagate_url, 'url')
         self.on_trait_change(self._rebuild_url, 'ip')
         self.on_trait_change(self._rebuild_url, 'transport')
         self.on_trait_change(self._rebuild_url, 'regport')
     
     def _rebuild_url(self):
         self.url = "%s://%s:%i"%(self.transport, self.ip, self.regport)
         
     def _propagate_url(self):
         """Ensure self.url contains full transport://interface:port"""
         if self.url:
             iface = self.url.split('://',1)
             if len(iface) == 2:
                 self.transport,iface = iface
             iface = iface.split(':')
             self.ip = iface[0]
             if iface[1]:
                 self.regport = int(iface[1])
 
 #-----------------------------------------------------------------------------
 # argparse argument extenders
 #-----------------------------------------------------------------------------
 
 
 def add_session_arguments(parser):
     paa = parser.add_argument
     paa('--ident',
         type=str, dest='SessionFactory.ident', 
         help='set the ZMQ and session identity [default: random uuid]',
         metavar='identity')
     # paa('--execkey',
     #     type=str, dest='SessionFactory.exec_key', 
     #     help='path to a file containing an execution key.',
     #     metavar='execkey')
     paa('--packer',
         type=str, dest='SessionFactory.packer', 
         help='method to serialize messages: {json,pickle} [default: json]',
         metavar='packer')
     paa('--unpacker',
         type=str, dest='SessionFactory.unpacker', 
         help='inverse function of `packer`.  Only necessary when using something other than json|pickle',
         metavar='packer')
 
 def add_registration_arguments(parser):
     paa = parser.add_argument
     paa('--ip',
         type=str, dest='RegistrationFactory.ip',
         help="The IP used for registration [default: localhost]",
         metavar='ip')
     paa('--transport',
         type=str, dest='RegistrationFactory.transport',
         help="The ZeroMQ transport used for registration [default: tcp]",
         metavar='transport')
     paa('--url',
         type=str, dest='RegistrationFactory.url', 
         help='set transport,ip,regport in one go, e.g. tcp://127.0.0.1:10101',
         metavar='url')
     paa('--regport',
         type=int, dest='RegistrationFactory.regport',
         help="The port used for registration [default: 10101]",
         metavar='ip')

IPython/zmq/parallel/heartmonitor.py

@@ -1,156 +1,158 b''
 #!/usr/bin/env python
 """
 A multi-heart Heartbeat system using PUB and XREP sockets. pings are sent out on the PUB,
 and hearts are tracked based on their XREQ identities.
 """
 
 from __future__ import print_function
 import time
 import uuid
 import logging
 
 import zmq
 from zmq.devices import ProcessDevice,ThreadDevice
 from zmq.eventloop import ioloop, zmqstream
 
+from IPython.utils.traitlets import Set, Instance, CFloat, Bool
+from factory import LoggingFactory
+
 class Heart(object):
     """A basic heart object for responding to a HeartMonitor.
     This is a simple wrapper with defaults for the most common
     Device model for responding to heartbeats.
     
     It simply builds a threadsafe zmq.FORWARDER Device, defaulting to using 
     SUB/XREQ for in/out.
     
     You can specify the XREQ's IDENTITY via the optional heart_id argument."""
     device=None
     id=None
     def __init__(self, in_addr, out_addr, in_type=zmq.SUB, out_type=zmq.XREQ, heart_id=None):
         self.device = ThreadDevice(zmq.FORWARDER, in_type, out_type)
         self.device.daemon=True
         self.device.connect_in(in_addr)
         self.device.connect_out(out_addr)
         if in_type == zmq.SUB:
             self.device.setsockopt_in(zmq.SUBSCRIBE, "")
         if heart_id is None:
             heart_id = str(uuid.uuid4())
         self.device.setsockopt_out(zmq.IDENTITY, heart_id)
         self.id = heart_id
     
     def start(self):
         return self.device.start()
         
-class HeartMonitor(object):
+class HeartMonitor(LoggingFactory):
     """A basic HeartMonitor class
     pingstream: a PUB stream
     pongstream: an XREP stream
     period: the period of the heartbeat in milliseconds"""
-    loop=None
-    pingstream=None
-    pongstream=None
-    period=None
-    hearts=None
-    on_probation=None
-    last_ping=None
-    # debug=False
     
-    def __init__(self, loop, pingstream, pongstream, period=1000):
-        self.loop = loop
-        self.period = period
+    period=CFloat(1000, config=True) # in milliseconds
+    
+    pingstream=Instance('zmq.eventloop.zmqstream.ZMQStream')
+    pongstream=Instance('zmq.eventloop.zmqstream.ZMQStream')
+    loop = Instance('zmq.eventloop.ioloop.IOLoop')
+    def _loop_default(self):
+        return ioloop.IOLoop.instance()
+    debug=Bool(False)
+    
+    # not settable:
+    hearts=Set()
+    responses=Set()
+    on_probation=Set()
+    last_ping=CFloat(0)
+    _new_handlers = Set()
+    _failure_handlers = Set()
+    lifetime = CFloat(0)
+    tic = CFloat(0)
+    
+    def __init__(self, **kwargs):
+        super(HeartMonitor, self).__init__(**kwargs)
         
-        self.pingstream = pingstream
-        self.pongstream = pongstream
         self.pongstream.on_recv(self.handle_pong)
-        
-        self.hearts = set()
-        self.responses = set()
-        self.on_probation = set()
-        self.lifetime = 0
-        self.tic = time.time()
-        
-        self._new_handlers = set()
-        self._failure_handlers = set()
     
     def start(self):
         self.caller = ioloop.PeriodicCallback(self.beat, self.period, self.loop)
         self.caller.start()
     
     def add_new_heart_handler(self, handler):
         """add a new handler for new hearts"""
-        logging.debug("heartbeat::new_heart_handler: %s"%handler)
+        self.log.debug("heartbeat::new_heart_handler: %s"%handler)
         self._new_handlers.add(handler)
         
     def add_heart_failure_handler(self, handler):
         """add a new handler for heart failure"""
-        logging.debug("heartbeat::new heart failure handler: %s"%handler)
+        self.log.debug("heartbeat::new heart failure handler: %s"%handler)
         self._failure_handlers.add(handler)
             
     def beat(self):
         self.pongstream.flush() 
         self.last_ping = self.lifetime
         
         toc = time.time()
         self.lifetime += toc-self.tic
         self.tic = toc
-        # logging.debug("heartbeat::%s"%self.lifetime)
+        # self.log.debug("heartbeat::%s"%self.lifetime)
         goodhearts = self.hearts.intersection(self.responses)
         missed_beats = self.hearts.difference(goodhearts)
         heartfailures = self.on_probation.intersection(missed_beats)
         newhearts = self.responses.difference(goodhearts)
         map(self.handle_new_heart, newhearts)
         map(self.handle_heart_failure, heartfailures)
         self.on_probation = missed_beats.intersection(self.hearts)
         self.responses = set()
         # print self.on_probation, self.hearts
-        # logging.debug("heartbeat::beat %.3f, %i beating hearts"%(self.lifetime, len(self.hearts)))
+        # self.log.debug("heartbeat::beat %.3f, %i beating hearts"%(self.lifetime, len(self.hearts)))
         self.pingstream.send(str(self.lifetime))
     
     def handle_new_heart(self, heart):
         if self._new_handlers:
             for handler in self._new_handlers:
                 handler(heart)
         else:
-            logging.info("heartbeat::yay, got new heart %s!"%heart)
+            self.log.info("heartbeat::yay, got new heart %s!"%heart)
         self.hearts.add(heart)
     
     def handle_heart_failure(self, heart):
         if self._failure_handlers:
             for handler in self._failure_handlers:
                 try:
                     handler(heart)
                 except Exception as e:
-                    logging.error("heartbeat::Bad Handler! %s"%handler, exc_info=True)
+                    self.log.error("heartbeat::Bad Handler! %s"%handler, exc_info=True)
                     pass
         else:
-            logging.info("heartbeat::Heart %s failed :("%heart)
+            self.log.info("heartbeat::Heart %s failed :("%heart)
         self.hearts.remove(heart)
         
     
     def handle_pong(self, msg):
         "a heart just beat"
         if msg[1] == str(self.lifetime):
             delta = time.time()-self.tic
-            # logging.debug("heartbeat::heart %r took %.2f ms to respond"%(msg[0], 1000*delta))
+            # self.log.debug("heartbeat::heart %r took %.2f ms to respond"%(msg[0], 1000*delta))
             self.responses.add(msg[0])
         elif msg[1] == str(self.last_ping):
             delta = time.time()-self.tic + (self.lifetime-self.last_ping)
-            logging.warn("heartbeat::heart %r missed a beat, and took %.2f ms to respond"%(msg[0], 1000*delta))
+            self.log.warn("heartbeat::heart %r missed a beat, and took %.2f ms to respond"%(msg[0], 1000*delta))
             self.responses.add(msg[0])
         else:
-            logging.warn("heartbeat::got bad heartbeat (possibly old?): %s (current=%.3f)"%
+            self.log.warn("heartbeat::got bad heartbeat (possibly old?): %s (current=%.3f)"%
             (msg[1],self.lifetime))
 
 
 if __name__ == '__main__':
     loop = ioloop.IOLoop.instance()
     context = zmq.Context()
     pub = context.socket(zmq.PUB)
     pub.bind('tcp://127.0.0.1:5555')
     xrep = context.socket(zmq.XREP)
     xrep.bind('tcp://127.0.0.1:5556')
     
     outstream = zmqstream.ZMQStream(pub, loop)
     instream = zmqstream.ZMQStream(xrep, loop)
     
     hb = HeartMonitor(loop, outstream, instream)
     
     loop.start()

IPython/zmq/parallel/hub.py

@@ -1,1047 +1,1045 b''
 #!/usr/bin/env python
 """The IPython Controller Hub with 0MQ
 This is the master object that handles connections from engines and clients,
 and monitors traffic through the various queues.
 """
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2010  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 from __future__ import print_function
 
 import sys
 from datetime import datetime
 import time
 import logging
 
 import zmq
 from zmq.eventloop import ioloop
 from zmq.eventloop.zmqstream import ZMQStream
 
 # internal:
 from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import HasTraits, Instance, Int, Str, Dict, Set, List, Bool
 from IPython.utils.importstring import import_item
 
 from entry_point import select_random_ports
-from factory import RegistrationFactory
+from factory import RegistrationFactory, LoggingFactory
 
 from streamsession import Message, wrap_exception, ISO8601
 from heartmonitor import HeartMonitor
 from util import validate_url_container
 
 try:
     from pymongo.binary import Binary
 except ImportError:
     MongoDB=None
 else:
     from mongodb import MongoDB
     
 #-----------------------------------------------------------------------------
 # Code
 #-----------------------------------------------------------------------------
 
 def _passer(*args, **kwargs):
     return
 
 def _printer(*args, **kwargs):
     print (args)
     print (kwargs)
 
 def init_record(msg):
     """Initialize a TaskRecord based on a request."""
     header = msg['header']
     return {
         'msg_id' : header['msg_id'],
         'header' : header,
         'content': msg['content'],
         'buffers': msg['buffers'],
         'submitted': datetime.strptime(header['date'], ISO8601),
         'client_uuid' : None,
         'engine_uuid' : None,
         'started': None,
         'completed': None,
         'resubmitted': None,
         'result_header' : None,
         'result_content' : None,
         'result_buffers' : None,
         'queue' : None,
         'pyin' : None,
         'pyout': None,
         'pyerr': None,
         'stdout': '',
         'stderr': '',
     }
 
 
 class EngineConnector(HasTraits):
     """A simple object for accessing the various zmq connections of an object.
     Attributes are:
     id (int): engine ID
     uuid (str): uuid (unused?)
     queue (str): identity of queue's XREQ socket
     registration (str): identity of registration XREQ socket
     heartbeat (str): identity of heartbeat XREQ socket
     """
     id=Int(0)
     queue=Str()
     control=Str()
     registration=Str()
     heartbeat=Str()
     pending=Set()
-    
-    def __init__(self, **kwargs):
-        super(EngineConnector, self).__init__(**kwargs)
-        logging.info("engine::Engine Connected: %i"%self.id)
 
 class HubFactory(RegistrationFactory):
     """The Configurable for setting up a Hub."""
     
     # port-pairs for monitoredqueues:
     hb = Instance(list, config=True)
     def _hb_default(self):
         return select_random_ports(2)
     
     mux = Instance(list, config=True)
     def _mux_default(self):
         return select_random_ports(2)
     
     task = Instance(list, config=True)
     def _task_default(self):
         return select_random_ports(2)
     
     control = Instance(list, config=True)
     def _control_default(self):
         return select_random_ports(2)
     
     iopub = Instance(list, config=True)
     def _iopub_default(self):
         return select_random_ports(2)
     
     # single ports:
     mon_port = Instance(int, config=True)
     def _mon_port_default(self):
         return select_random_ports(1)[0]
     
     query_port = Instance(int, config=True)
     def _query_port_default(self):
         return select_random_ports(1)[0]
     
     notifier_port = Instance(int, config=True)
     def _notifier_port_default(self):
         return select_random_ports(1)[0]
     
     ping = Int(1000, config=True) # ping frequency
     
     engine_ip = Str('127.0.0.1', config=True)
     engine_transport = Str('tcp', config=True)
     
     client_ip = Str('127.0.0.1', config=True)
     client_transport = Str('tcp', config=True)
     
     monitor_ip = Str('127.0.0.1', config=True)
     monitor_transport = Str('tcp', config=True)
     
     monitor_url = Str('')
     
     db_class = Str('IPython.zmq.parallel.dictdb.DictDB', config=True)
     
     # not configurable
     db = Instance('IPython.zmq.parallel.dictdb.BaseDB')
     heartmonitor = Instance('IPython.zmq.parallel.heartmonitor.HeartMonitor')
     subconstructors = List()
     _constructed = Bool(False)
     
     def _ip_changed(self, name, old, new):
         self.engine_ip = new
         self.client_ip = new
         self.monitor_ip = new
         self._update_monitor_url()
     
     def _update_monitor_url(self):
         self.monitor_url = "%s://%s:%i"%(self.monitor_transport, self.monitor_ip, self.mon_port)
     
     def _transport_changed(self, name, old, new):
         self.engine_transport = new
         self.client_transport = new
         self.monitor_transport = new
         self._update_monitor_url()
         
     def __init__(self, **kwargs):
         super(HubFactory, self).__init__(**kwargs)
         self._update_monitor_url()
         # self.on_trait_change(self._sync_ips, 'ip')
         # self.on_trait_change(self._sync_transports, 'transport')
         self.subconstructors.append(self.construct_hub)
     
     
     def construct(self):
         assert not self._constructed, "already constructed!"
         
         for subc in self.subconstructors:
             subc()
         
         self._constructed = True
         
     
     def start(self):
         assert self._constructed, "must be constructed by self.construct() first!"
         self.heartmonitor.start()
-        logging.info("Heartmonitor started")
+        self.log.info("Heartmonitor started")
     
     def construct_hub(self):
         """construct"""
         client_iface = "%s://%s:"%(self.client_transport, self.client_ip) + "%i"
         engine_iface = "%s://%s:"%(self.engine_transport, self.engine_ip) + "%i"
         
         ctx = self.context
         loop = self.loop
         
         # Registrar socket
         reg = ZMQStream(ctx.socket(zmq.XREP), loop)
         reg.bind(client_iface % self.regport)
-        logging.info("Hub listening on %s for registration."%(client_iface%self.regport))
+        self.log.info("Hub listening on %s for registration."%(client_iface%self.regport))
         if self.client_ip != self.engine_ip:
             reg.bind(engine_iface % self.regport)
-            logging.info("Hub listening on %s for registration."%(engine_iface%self.regport))
+            self.log.info("Hub listening on %s for registration."%(engine_iface%self.regport))
         
         ### Engine connections ###
 
         # heartbeat
         hpub = ctx.socket(zmq.PUB)
         hpub.bind(engine_iface % self.hb[0])
         hrep = ctx.socket(zmq.XREP)
         hrep.bind(engine_iface % self.hb[1])
-
-        self.heartmonitor = HeartMonitor(loop, ZMQStream(hpub,loop), ZMQStream(hrep,loop), self.ping)
+        self.heartmonitor = HeartMonitor(loop=loop, pingstream=ZMQStream(hpub,loop), pongstream=ZMQStream(hrep,loop), 
+                                period=self.ping, logname=self.log.name)
 
         ### Client connections ###
         # Clientele socket
         c = ZMQStream(ctx.socket(zmq.XREP), loop)
         c.bind(client_iface%self.query_port)
         # Notifier socket
         n = ZMQStream(ctx.socket(zmq.PUB), loop)
         n.bind(client_iface%self.notifier_port)
 
         ### build and launch the queues ###
 
         # monitor socket
         sub = ctx.socket(zmq.SUB)
         sub.setsockopt(zmq.SUBSCRIBE, "")
         sub.bind(self.monitor_url)
         sub = ZMQStream(sub, loop)
         
         # connect the db
         self.db = import_item(self.db_class)()
         time.sleep(.25)
 
         # build connection dicts
         self.engine_addrs = {
             'control' : engine_iface%self.control[1],
             'mux': engine_iface%self.mux[1],
             'heartbeat': (engine_iface%self.hb[0], engine_iface%self.hb[1]),
             'task' : engine_iface%self.task[1],
             'iopub' : engine_iface%self.iopub[1],
             # 'monitor' : engine_iface%self.mon_port,
             }
 
         self.client_addrs = {
             'control' : client_iface%self.control[0],
             'query': client_iface%self.query_port,
             'mux': client_iface%self.mux[0],
             'task' : client_iface%self.task[0],
             'iopub' : client_iface%self.iopub[0],
             'notification': client_iface%self.notifier_port
             }
-        logging.debug("hub::Hub engine addrs: %s"%self.engine_addrs)
-        logging.debug("hub::Hub client addrs: %s"%self.client_addrs)
+        self.log.debug("hub::Hub engine addrs: %s"%self.engine_addrs)
+        self.log.debug("hub::Hub client addrs: %s"%self.client_addrs)
         self.hub = Hub(loop=loop, session=self.session, monitor=sub, heartmonitor=self.heartmonitor,
                 registrar=reg, clientele=c, notifier=n, db=self.db,
-                engine_addrs=self.engine_addrs, client_addrs=self.client_addrs)
+                engine_addrs=self.engine_addrs, client_addrs=self.client_addrs,
+                logname=self.log.name)
     
 
-class Hub(HasTraits):
+class Hub(LoggingFactory):
     """The IPython Controller Hub with 0MQ connections
     
     Parameters
     ==========
     loop: zmq IOLoop instance
     session: StreamSession object
     <removed> context: zmq context for creating new connections (?)
     queue: ZMQStream for monitoring the command queue (SUB)
     registrar: ZMQStream for engine registration requests (XREP)
     heartbeat: HeartMonitor object checking the pulse of the engines
     clientele: ZMQStream for client connections (XREP)
                 not used for jobs, only query/control commands
     notifier: ZMQStream for broadcasting engine registration changes (PUB)
     db: connection to db for out of memory logging of commands
                 NotImplemented
     engine_addrs: dict of zmq connection information for engines to connect
                 to the queues.
     client_addrs: dict of zmq connection information for engines to connect
                 to the queues.
     """
     # internal data structures:
     ids=Set() # engine IDs
     keytable=Dict()
     by_ident=Dict()
     engines=Dict()
     clients=Dict()
     hearts=Dict()
     pending=Set()
     queues=Dict()  # pending msg_ids keyed by engine_id
     tasks=Dict() # pending msg_ids submitted as tasks, keyed by client_id
     completed=Dict() # completed msg_ids keyed by engine_id
     all_completed=Set() # completed msg_ids keyed by engine_id
     # mia=None
     incoming_registrations=Dict()
     registration_timeout=Int()
     _idcounter=Int(0)
     
     # objects from constructor:
     loop=Instance(ioloop.IOLoop)
     registrar=Instance(ZMQStream)
     clientele=Instance(ZMQStream)
     monitor=Instance(ZMQStream)
     heartmonitor=Instance(HeartMonitor)
     notifier=Instance(ZMQStream)
     db=Instance(object)
     client_addrs=Dict()
     engine_addrs=Dict()
     
     
     def __init__(self, **kwargs):
         """
         # universal:
         loop: IOLoop for creating future connections
         session: streamsession for sending serialized data
         # engine:
         queue: ZMQStream for monitoring queue messages
         registrar: ZMQStream for engine registration
         heartbeat: HeartMonitor object for tracking engines
         # client:
         clientele: ZMQStream for client connections
         # extra:
         db: ZMQStream for db connection (NotImplemented)
         engine_addrs: zmq address/protocol dict for engine connections
         client_addrs: zmq address/protocol dict for client connections
         """
         
         super(Hub, self).__init__(**kwargs)
         self.registration_timeout = max(5000, 2*self.heartmonitor.period)
         
         # validate connection dicts:
         validate_url_container(self.client_addrs)
         validate_url_container(self.engine_addrs)
         
         # register our callbacks
         self.registrar.on_recv(self.dispatch_register_request)
         self.clientele.on_recv(self.dispatch_client_msg)
         self.monitor.on_recv(self.dispatch_monitor_traffic)
         
         self.heartmonitor.add_heart_failure_handler(self.handle_heart_failure)
         self.heartmonitor.add_new_heart_handler(self.handle_new_heart)
         
         self.monitor_handlers = { 'in' : self.save_queue_request,
                                 'out': self.save_queue_result,
                                 'intask': self.save_task_request,
                                 'outtask': self.save_task_result,
                                 'tracktask': self.save_task_destination,
                                 'incontrol': _passer,
                                 'outcontrol': _passer,
                                 'iopub': self.save_iopub_message,
         }
         
         self.client_handlers = {'queue_request': self.queue_status,
                                 'result_request': self.get_results,
                                 'purge_request': self.purge_results,
                                 'load_request': self.check_load,
                                 'resubmit_request': self.resubmit_task,
                                 'shutdown_request': self.shutdown_request,
                                 }
         
         self.registrar_handlers = {'registration_request' : self.register_engine,
                                 'unregistration_request' : self.unregister_engine,
                                 'connection_request': self.connection_request,
         }
         
-        logging.info("hub::created hub")
+        self.log.info("hub::created hub")
     
     @property
     def _next_id(self):
         """gemerate a new ID.
         
         No longer reuse old ids, just count from 0."""
         newid = self._idcounter
         self._idcounter += 1
         return newid
         # newid = 0
         # incoming = [id[0] for id in self.incoming_registrations.itervalues()]
         # # print newid, self.ids, self.incoming_registrations
         # while newid in self.ids or newid in incoming:
         #     newid += 1
         # return newid
     
     #-----------------------------------------------------------------------------
     # message validation
     #-----------------------------------------------------------------------------
     
     def _validate_targets(self, targets):
         """turn any valid targets argument into a list of integer ids"""
         if targets is None:
             # default to all
             targets = self.ids
             
         if isinstance(targets, (int,str,unicode)):
             # only one target specified
             targets = [targets]
         _targets = []
         for t in targets:
             # map raw identities to ids
             if isinstance(t, (str,unicode)):
                 t = self.by_ident.get(t, t)
             _targets.append(t)
         targets = _targets
         bad_targets = [ t for t in targets if t not in self.ids ]
         if bad_targets:
             raise IndexError("No Such Engine: %r"%bad_targets)
         if not targets:
             raise IndexError("No Engines Registered")
         return targets
     
     def _validate_client_msg(self, msg):
         """validates and unpacks headers of a message. Returns False if invalid,
         (ident, header, parent, content)"""
         client_id = msg[0]
         try:
             msg = self.session.unpack_message(msg[1:], content=True)
         except:
-            logging.error("client::Invalid Message %s"%msg, exc_info=True)
+            self.log.error("client::Invalid Message %s"%msg, exc_info=True)
             return False
         
         msg_type = msg.get('msg_type', None)
         if msg_type is None:
             return False
         header = msg.get('header')
         # session doesn't handle split content for now:
         return client_id, msg
         
     
     #-----------------------------------------------------------------------------
     # dispatch methods (1 per stream)
     #-----------------------------------------------------------------------------
     
     def dispatch_register_request(self, msg):
         """"""
-        logging.debug("registration::dispatch_register_request(%s)"%msg)
+        self.log.debug("registration::dispatch_register_request(%s)"%msg)
         idents,msg = self.session.feed_identities(msg)
         if not idents:
-            logging.error("Bad Queue Message: %s"%msg, exc_info=True)
+            self.log.error("Bad Queue Message: %s"%msg, exc_info=True)
             return
         try:
             msg = self.session.unpack_message(msg,content=True)
         except:
-            logging.error("registration::got bad registration message: %s"%msg, exc_info=True)
+            self.log.error("registration::got bad registration message: %s"%msg, exc_info=True)
             return
         
         msg_type = msg['msg_type']
         content = msg['content']
         
         handler = self.registrar_handlers.get(msg_type, None)
         if handler is None:
-            logging.error("registration::got bad registration message: %s"%msg)
+            self.log.error("registration::got bad registration message: %s"%msg)
         else:
             handler(idents, msg)
     
     def dispatch_monitor_traffic(self, msg):
         """all ME and Task queue messages come through here, as well as
         IOPub traffic."""
-        logging.debug("monitor traffic: %s"%msg[:2])
+        self.log.debug("monitor traffic: %s"%msg[:2])
         switch = msg[0]
         idents, msg = self.session.feed_identities(msg[1:])
         if not idents:
-            logging.error("Bad Monitor Message: %s"%msg)
+            self.log.error("Bad Monitor Message: %s"%msg)
             return
         handler = self.monitor_handlers.get(switch, None)
         if handler is not None:
             handler(idents, msg)
         else:
-            logging.error("Invalid monitor topic: %s"%switch)
+            self.log.error("Invalid monitor topic: %s"%switch)
         
     
     def dispatch_client_msg(self, msg):
         """Route messages from clients"""
         idents, msg = self.session.feed_identities(msg)
         if not idents:
-            logging.error("Bad Client Message: %s"%msg)
+            self.log.error("Bad Client Message: %s"%msg)
             return
         client_id = idents[0]
         try:
             msg = self.session.unpack_message(msg, content=True)
         except:
             content = wrap_exception()
-            logging.error("Bad Client Message: %s"%msg, exc_info=True)
+            self.log.error("Bad Client Message: %s"%msg, exc_info=True)
             self.session.send(self.clientele, "hub_error", ident=client_id, 
                     content=content)
             return
         
         # print client_id, header, parent, content
         #switch on message type:
         msg_type = msg['msg_type']
-        logging.info("client:: client %s requested %s"%(client_id, msg_type))
+        self.log.info("client:: client %s requested %s"%(client_id, msg_type))
         handler = self.client_handlers.get(msg_type, None)
         try:
             assert handler is not None, "Bad Message Type: %s"%msg_type
         except:
             content = wrap_exception()
-            logging.error("Bad Message Type: %s"%msg_type, exc_info=True)
+            self.log.error("Bad Message Type: %s"%msg_type, exc_info=True)
             self.session.send(self.clientele, "hub_error", ident=client_id, 
                     content=content)
             return
         else:
             handler(client_id, msg)
             
     def dispatch_db(self, msg):
         """"""
         raise NotImplementedError
     
     #---------------------------------------------------------------------------
     # handler methods (1 per event)
     #---------------------------------------------------------------------------
     
     #----------------------- Heartbeat --------------------------------------
     
     def handle_new_heart(self, heart):
         """handler to attach to heartbeater.
         Called when a new heart starts to beat.
         Triggers completion of registration."""
-        logging.debug("heartbeat::handle_new_heart(%r)"%heart)
+        self.log.debug("heartbeat::handle_new_heart(%r)"%heart)
         if heart not in self.incoming_registrations:
-            logging.info("heartbeat::ignoring new heart: %r"%heart)
+            self.log.info("heartbeat::ignoring new heart: %r"%heart)
         else:
             self.finish_registration(heart)
         
     
     def handle_heart_failure(self, heart):
         """handler to attach to heartbeater.
         called when a previously registered heart fails to respond to beat request.
         triggers unregistration"""
-        logging.debug("heartbeat::handle_heart_failure(%r)"%heart)
+        self.log.debug("heartbeat::handle_heart_failure(%r)"%heart)
         eid = self.hearts.get(heart, None)
         queue = self.engines[eid].queue
         if eid is None:
-            logging.info("heartbeat::ignoring heart failure %r"%heart)
+            self.log.info("heartbeat::ignoring heart failure %r"%heart)
         else:
             self.unregister_engine(heart, dict(content=dict(id=eid, queue=queue)))
     
     #----------------------- MUX Queue Traffic ------------------------------
     
     def save_queue_request(self, idents, msg):
         if len(idents) < 2:
-            logging.error("invalid identity prefix: %s"%idents)
+            self.log.error("invalid identity prefix: %s"%idents)
             return
         queue_id, client_id = idents[:2]
         try:
             msg = self.session.unpack_message(msg, content=False)
         except:
-            logging.error("queue::client %r sent invalid message to %r: %s"%(client_id, queue_id, msg), exc_info=True)
+            self.log.error("queue::client %r sent invalid message to %r: %s"%(client_id, queue_id, msg), exc_info=True)
             return
         
         eid = self.by_ident.get(queue_id, None)
         if eid is None:
-            logging.error("queue::target %r not registered"%queue_id)
-            logging.debug("queue::    valid are: %s"%(self.by_ident.keys()))
+            self.log.error("queue::target %r not registered"%queue_id)
+            self.log.debug("queue::    valid are: %s"%(self.by_ident.keys()))
             return
             
         header = msg['header']
         msg_id = header['msg_id']
         record = init_record(msg)
         record['engine_uuid'] = queue_id
         record['client_uuid'] = client_id
         record['queue'] = 'mux'
         if MongoDB is not None and isinstance(self.db, MongoDB):
             record['buffers'] = map(Binary, record['buffers'])
         self.pending.add(msg_id)
         self.queues[eid].append(msg_id)
         self.db.add_record(msg_id, record)
     
     def save_queue_result(self, idents, msg):
         if len(idents) < 2:
-            logging.error("invalid identity prefix: %s"%idents)
+            self.log.error("invalid identity prefix: %s"%idents)
             return
             
         client_id, queue_id = idents[:2]
         try:
             msg = self.session.unpack_message(msg, content=False)
         except:
-            logging.error("queue::engine %r sent invalid message to %r: %s"%(
+            self.log.error("queue::engine %r sent invalid message to %r: %s"%(
                     queue_id,client_id, msg), exc_info=True)
             return
         
         eid = self.by_ident.get(queue_id, None)
         if eid is None:
-            logging.error("queue::unknown engine %r is sending a reply: "%queue_id)
-            logging.debug("queue::       %s"%msg[2:])
+            self.log.error("queue::unknown engine %r is sending a reply: "%queue_id)
+            self.log.debug("queue::       %s"%msg[2:])
             return
         
         parent = msg['parent_header']
         if not parent:
             return
         msg_id = parent['msg_id']
         if msg_id in self.pending:
             self.pending.remove(msg_id)
             self.all_completed.add(msg_id)
             self.queues[eid].remove(msg_id)
             self.completed[eid].append(msg_id)
             rheader = msg['header']
             completed = datetime.strptime(rheader['date'], ISO8601)
             started = rheader.get('started', None)
             if started is not None:
                 started = datetime.strptime(started, ISO8601)
             result = {
                 'result_header' : rheader,
                 'result_content': msg['content'],
                 'started' : started,
                 'completed' : completed
             }
             if MongoDB is not None and isinstance(self.db, MongoDB):
                 result['result_buffers'] = map(Binary, msg['buffers'])
             else:
                 result['result_buffers'] = msg['buffers']
             self.db.update_record(msg_id, result)
         else:
-            logging.debug("queue:: unknown msg finished %s"%msg_id)
+            self.log.debug("queue:: unknown msg finished %s"%msg_id)
             
     #--------------------- Task Queue Traffic ------------------------------
     
     def save_task_request(self, idents, msg):
         """Save the submission of a task."""
         client_id = idents[0]
         
         try:
             msg = self.session.unpack_message(msg, content=False)
         except:
-            logging.error("task::client %r sent invalid task message: %s"%(
+            self.log.error("task::client %r sent invalid task message: %s"%(
                     client_id, msg), exc_info=True)
             return
         record = init_record(msg)
         if MongoDB is not None and isinstance(self.db, MongoDB):
             record['buffers'] = map(Binary, record['buffers'])
         record['client_uuid'] = client_id
         record['queue'] = 'task'
         header = msg['header']
         msg_id = header['msg_id']
         self.pending.add(msg_id)
         self.db.add_record(msg_id, record)
     
     def save_task_result(self, idents, msg):
         """save the result of a completed task."""
         client_id = idents[0]
         try:
             msg = self.session.unpack_message(msg, content=False)
         except:
-            logging.error("task::invalid task result message send to %r: %s"%(
+            self.log.error("task::invalid task result message send to %r: %s"%(
                     client_id, msg), exc_info=True)
             raise
             return
         
         parent = msg['parent_header']
         if not parent:
             # print msg
-            logging.warn("Task %r had no parent!"%msg)
+            self.log.warn("Task %r had no parent!"%msg)
             return
         msg_id = parent['msg_id']
         
         header = msg['header']
         engine_uuid = header.get('engine', None)
         eid = self.by_ident.get(engine_uuid, None)
         
         if msg_id in self.pending:
             self.pending.remove(msg_id)
             self.all_completed.add(msg_id)
             if eid is not None:
                 self.completed[eid].append(msg_id)
                 if msg_id in self.tasks[eid]:
                     self.tasks[eid].remove(msg_id)
             completed = datetime.strptime(header['date'], ISO8601)
             started = header.get('started', None)
             if started is not None:
                 started = datetime.strptime(started, ISO8601)
             result = {
                 'result_header' : header,
                 'result_content': msg['content'],
                 'started' : started,
                 'completed' : completed,
                 'engine_uuid': engine_uuid
             }
             if MongoDB is not None and isinstance(self.db, MongoDB):
                 result['result_buffers'] = map(Binary, msg['buffers'])
             else:
                 result['result_buffers'] = msg['buffers']
             self.db.update_record(msg_id, result)
             
         else:
-            logging.debug("task::unknown task %s finished"%msg_id)
+            self.log.debug("task::unknown task %s finished"%msg_id)
     
     def save_task_destination(self, idents, msg):
         try:
             msg = self.session.unpack_message(msg, content=True)
         except:
-            logging.error("task::invalid task tracking message", exc_info=True)
+            self.log.error("task::invalid task tracking message", exc_info=True)
             return
         content = msg['content']
         print (content)
         msg_id = content['msg_id']
         engine_uuid = content['engine_id']
         eid = self.by_ident[engine_uuid]
         
-        logging.info("task::task %s arrived on %s"%(msg_id, eid))
+        self.log.info("task::task %s arrived on %s"%(msg_id, eid))
         # if msg_id in self.mia:
         #     self.mia.remove(msg_id)
         # else:
-        #     logging.debug("task::task %s not listed as MIA?!"%(msg_id))
+        #     self.log.debug("task::task %s not listed as MIA?!"%(msg_id))
         
         self.tasks[eid].append(msg_id)
         # self.pending[msg_id][1].update(received=datetime.now(),engine=(eid,engine_uuid))
         self.db.update_record(msg_id, dict(engine_uuid=engine_uuid))
     
     def mia_task_request(self, idents, msg):
         raise NotImplementedError
         client_id = idents[0]
         # content = dict(mia=self.mia,status='ok')
         # self.session.send('mia_reply', content=content, idents=client_id)
         
         
     #--------------------- IOPub Traffic ------------------------------
     
     def save_iopub_message(self, topics, msg):
         """save an iopub message into the db"""
         print (topics)
         try:
             msg = self.session.unpack_message(msg, content=True)
         except:
-            logging.error("iopub::invalid IOPub message", exc_info=True)
+            self.log.error("iopub::invalid IOPub message", exc_info=True)
             return
         
         parent = msg['parent_header']
         if not parent:
-            logging.error("iopub::invalid IOPub message: %s"%msg)
+            self.log.error("iopub::invalid IOPub message: %s"%msg)
             return
         msg_id = parent['msg_id']
         msg_type = msg['msg_type']
         content = msg['content']
         
         # ensure msg_id is in db
         try:
             rec = self.db.get_record(msg_id)
         except:
-            logging.error("iopub::IOPub message has invalid parent", exc_info=True)
+            self.log.error("iopub::IOPub message has invalid parent", exc_info=True)
             return
         # stream
         d = {}
         if msg_type == 'stream':
             name = content['name']
             s = rec[name] or ''
             d[name] = s + content['data']
             
         elif msg_type == 'pyerr':
             d['pyerr'] = content
         else:
             d[msg_type] = content['data']
         
         self.db.update_record(msg_id, d)
         
     
             
     #-------------------------------------------------------------------------
     # Registration requests
     #-------------------------------------------------------------------------
         
     def connection_request(self, client_id, msg):
         """Reply with connection addresses for clients."""
-        logging.info("client::client %s connected"%client_id)
+        self.log.info("client::client %s connected"%client_id)
         content = dict(status='ok')
         content.update(self.client_addrs)
         jsonable = {}
         for k,v in self.keytable.iteritems():
             jsonable[str(k)] = v
         content['engines'] = jsonable
         self.session.send(self.registrar, 'connection_reply', content, parent=msg, ident=client_id)
     
     def register_engine(self, reg, msg):
         """Register a new engine."""
         content = msg['content']
         try:
             queue = content['queue']
         except KeyError:
-            logging.error("registration::queue not specified", exc_info=True)
+            self.log.error("registration::queue not specified", exc_info=True)
             return
         heart = content.get('heartbeat', None)
         """register a new engine, and create the socket(s) necessary"""
         eid = self._next_id
         # print (eid, queue, reg, heart)
         
-        logging.debug("registration::register_engine(%i, %r, %r, %r)"%(eid, queue, reg, heart))
+        self.log.debug("registration::register_engine(%i, %r, %r, %r)"%(eid, queue, reg, heart))
         
         content = dict(id=eid,status='ok')
         content.update(self.engine_addrs)
         # check if requesting available IDs:
         if queue in self.by_ident:
             try:
                 raise KeyError("queue_id %r in use"%queue)
             except:
                 content = wrap_exception()
-                logging.error("queue_id %r in use"%queue, exc_info=True)
+                self.log.error("queue_id %r in use"%queue, exc_info=True)
         elif heart in self.hearts: # need to check unique hearts?
             try:
                 raise KeyError("heart_id %r in use"%heart)
             except:
-                logging.error("heart_id %r in use"%heart, exc_info=True)
+                self.log.error("heart_id %r in use"%heart, exc_info=True)
                 content = wrap_exception()
         else:
             for h, pack in self.incoming_registrations.iteritems():
                 if heart == h:
                     try:
                         raise KeyError("heart_id %r in use"%heart)
                     except:
-                        logging.error("heart_id %r in use"%heart, exc_info=True)
+                        self.log.error("heart_id %r in use"%heart, exc_info=True)
                         content = wrap_exception()
                     break
                 elif queue == pack[1]:
                     try:
                         raise KeyError("queue_id %r in use"%queue)
                     except:
-                        logging.error("queue_id %r in use"%queue, exc_info=True)
+                        self.log.error("queue_id %r in use"%queue, exc_info=True)
                         content = wrap_exception()
                     break
         
         msg = self.session.send(self.registrar, "registration_reply", 
                 content=content, 
                 ident=reg)
         
         if content['status'] == 'ok':
             if heart in self.heartmonitor.hearts:
                 # already beating
                 self.incoming_registrations[heart] = (eid,queue,reg[0],None)
                 self.finish_registration(heart)
             else:
                 purge = lambda : self._purge_stalled_registration(heart)
                 dc = ioloop.DelayedCallback(purge, self.registration_timeout, self.loop)
                 dc.start()
                 self.incoming_registrations[heart] = (eid,queue,reg[0],dc)
         else:
-            logging.error("registration::registration %i failed: %s"%(eid, content['evalue']))
+            self.log.error("registration::registration %i failed: %s"%(eid, content['evalue']))
         return eid
     
     def unregister_engine(self, ident, msg):
         """Unregister an engine that explicitly requested to leave."""
         try:
             eid = msg['content']['id']
         except:
-            logging.error("registration::bad engine id for unregistration: %s"%ident, exc_info=True)
+            self.log.error("registration::bad engine id for unregistration: %s"%ident, exc_info=True)
             return
-        logging.info("registration::unregister_engine(%s)"%eid)
+        self.log.info("registration::unregister_engine(%s)"%eid)
         content=dict(id=eid, queue=self.engines[eid].queue)
         self.ids.remove(eid)
         self.keytable.pop(eid)
         ec = self.engines.pop(eid)
         self.hearts.pop(ec.heartbeat)
         self.by_ident.pop(ec.queue)
         self.completed.pop(eid)
         for msg_id in self.queues.pop(eid):
             msg = self.pending.remove(msg_id)
             ############## TODO: HANDLE IT ################
         
         if self.notifier:
             self.session.send(self.notifier, "unregistration_notification", content=content)
     
     def finish_registration(self, heart):
         """Second half of engine registration, called after our HeartMonitor
         has received a beat from the Engine's Heart."""
         try: 
             (eid,queue,reg,purge) = self.incoming_registrations.pop(heart)
         except KeyError:
-            logging.error("registration::tried to finish nonexistant registration", exc_info=True)
+            self.log.error("registration::tried to finish nonexistant registration", exc_info=True)
             return
-        logging.info("registration::finished registering engine %i:%r"%(eid,queue))
+        self.log.info("registration::finished registering engine %i:%r"%(eid,queue))
         if purge is not None:
             purge.stop()
         control = queue
         self.ids.add(eid)
         self.keytable[eid] = queue
         self.engines[eid] = EngineConnector(id=eid, queue=queue, registration=reg, 
                                     control=control, heartbeat=heart)
         self.by_ident[queue] = eid
         self.queues[eid] = list()
         self.tasks[eid] = list()
         self.completed[eid] = list()
         self.hearts[heart] = eid
         content = dict(id=eid, queue=self.engines[eid].queue)
         if self.notifier:
             self.session.send(self.notifier, "registration_notification", content=content)
+        self.log.info("engine::Engine Connected: %i"%eid)
     
     def _purge_stalled_registration(self, heart):
         if heart in self.incoming_registrations:
             eid = self.incoming_registrations.pop(heart)[0]
-            logging.info("registration::purging stalled registration: %i"%eid)
+            self.log.info("registration::purging stalled registration: %i"%eid)
         else:
             pass
             
     #-------------------------------------------------------------------------
     # Client Requests
     #-------------------------------------------------------------------------
     
     def shutdown_request(self, client_id, msg):
         """handle shutdown request."""
         # s = self.context.socket(zmq.XREQ)
         # s.connect(self.client_connections['mux'])
         # time.sleep(0.1)
         # for eid,ec in self.engines.iteritems():
         #     self.session.send(s, 'shutdown_request', content=dict(restart=False), ident=ec.queue)
         # time.sleep(1)
         self.session.send(self.clientele, 'shutdown_reply', content={'status': 'ok'}, ident=client_id)
         dc = ioloop.DelayedCallback(lambda : self._shutdown(), 1000, self.loop)
         dc.start()
     
     def _shutdown(self):
-        logging.info("hub::hub shutting down.")
+        self.log.info("hub::hub shutting down.")
         time.sleep(0.1)
         sys.exit(0)
         
     
     def check_load(self, client_id, msg):
         content = msg['content']
         try:
             targets = content['targets']
             targets = self._validate_targets(targets)
         except:
             content = wrap_exception()
             self.session.send(self.clientele, "hub_error", 
                     content=content, ident=client_id)
             return
         
         content = dict(status='ok')
         # loads = {}
         for t in targets:
             content[bytes(t)] = len(self.queues[t])+len(self.tasks[t])
         self.session.send(self.clientele, "load_reply", content=content, ident=client_id)
             
     
     def queue_status(self, client_id, msg):
         """Return the Queue status of one or more targets.
         if verbose: return the msg_ids
         else: return len of each type.
         keys: queue (pending MUX jobs)
             tasks (pending Task jobs)
             completed (finished jobs from both queues)"""
         content = msg['content']
         targets = content['targets']
         try:
             targets = self._validate_targets(targets)
         except:
             content = wrap_exception()
             self.session.send(self.clientele, "hub_error", 
                     content=content, ident=client_id)
             return
         verbose = content.get('verbose', False)
         content = dict(status='ok')
         for t in targets:
             queue = self.queues[t]
             completed = self.completed[t]
             tasks = self.tasks[t]
             if not verbose:
                 queue = len(queue)
                 completed = len(completed)
                 tasks = len(tasks)
             content[bytes(t)] = {'queue': queue, 'completed': completed , 'tasks': tasks}
             # pending
         self.session.send(self.clientele, "queue_reply", content=content, ident=client_id)
     
     def purge_results(self, client_id, msg):
         """Purge results from memory. This method is more valuable before we move
         to a DB based message storage mechanism."""
         content = msg['content']
         msg_ids = content.get('msg_ids', [])
         reply = dict(status='ok')
         if msg_ids == 'all':
             self.db.drop_matching_records(dict(completed={'$ne':None}))
         else:
             for msg_id in msg_ids:
                 if msg_id in self.all_completed:
                     self.db.drop_record(msg_id)
                 else:
                     if msg_id in self.pending:
                         try:
                             raise IndexError("msg pending: %r"%msg_id)
                         except:
                             reply = wrap_exception()
                     else:
                         try:
                             raise IndexError("No such msg: %r"%msg_id)
                         except:
                             reply = wrap_exception()
                     break
             eids = content.get('engine_ids', [])
             for eid in eids:
                 if eid not in self.engines:
                     try:
                         raise IndexError("No such engine: %i"%eid)
                     except:
                         reply = wrap_exception()
                     break
                 msg_ids = self.completed.pop(eid)
                 uid = self.engines[eid].queue
                 self.db.drop_matching_records(dict(engine_uuid=uid, completed={'$ne':None}))
         
         self.session.send(self.clientele, 'purge_reply', content=reply, ident=client_id)
     
     def resubmit_task(self, client_id, msg, buffers):
         """Resubmit a task."""
         raise NotImplementedError
     
     def get_results(self, client_id, msg):
         """Get the result of 1 or more messages."""
         content = msg['content']
         msg_ids = sorted(set(content['msg_ids']))
         statusonly = content.get('status_only', False)
         pending = []
         completed = []
         content = dict(status='ok')
         content['pending'] = pending
         content['completed'] = completed
         buffers = []
         if not statusonly:
             content['results'] = {}
             records = self.db.find_records(dict(msg_id={'$in':msg_ids}))
         for msg_id in msg_ids:
             if msg_id in self.pending:
                 pending.append(msg_id)
             elif msg_id in self.all_completed:
                 completed.append(msg_id)
                 if not statusonly:
                     rec = records[msg_id]
                     io_dict = {}
                     for key in 'pyin pyout pyerr stdout stderr'.split():
                             io_dict[key] = rec[key]
                     content[msg_id] = { 'result_content': rec['result_content'],
                                         'header': rec['header'],
                                         'result_header' : rec['result_header'],
                                         'io' : io_dict,
                                       }
                     buffers.extend(map(str, rec['result_buffers']))
             else:
                 try:
                     raise KeyError('No such message: '+msg_id)
                 except:
                     content = wrap_exception()
                 break
         self.session.send(self.clientele, "result_reply", content=content, 
                                             parent=msg, ident=client_id,
                                             buffers=buffers)
 

IPython/zmq/parallel/ipclusterapp.py

@@ -1,502 +1,503 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 The ipcluster application.
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import logging
 import os
 import signal
 import logging
 
 from zmq.eventloop import ioloop
 
 from IPython.external.argparse import ArgumentParser, SUPPRESS
 from IPython.utils.importstring import import_item
 from IPython.zmq.parallel.clusterdir import (
     ApplicationWithClusterDir, ClusterDirConfigLoader,
     ClusterDirError, PIDFileError
 )
 
 
 #-----------------------------------------------------------------------------
 # Module level variables
 #-----------------------------------------------------------------------------
 
 
 default_config_file_name = u'ipcluster_config.py'
 
 
 _description = """\
 Start an IPython cluster for parallel computing.\n\n
 
 An IPython cluster consists of 1 controller and 1 or more engines.
 This command automates the startup of these processes using a wide
 range of startup methods (SSH, local processes, PBS, mpiexec,
 Windows HPC Server 2008). To start a cluster with 4 engines on your
 local host simply do 'ipcluster start -n 4'. For more complex usage 
 you will typically do 'ipcluster create -p mycluster', then edit
 configuration files, followed by 'ipcluster start -p mycluster -n 4'.
 """
 
 
 # Exit codes for ipcluster
 
 # This will be the exit code if the ipcluster appears to be running because
 # a .pid file exists
 ALREADY_STARTED = 10
 
 
 # This will be the exit code if ipcluster stop is run, but there is not .pid
 # file to be found.
 ALREADY_STOPPED = 11
 
 
 #-----------------------------------------------------------------------------
 # Command line options
 #-----------------------------------------------------------------------------
 
 
 class IPClusterAppConfigLoader(ClusterDirConfigLoader):
 
     def _add_arguments(self):
         # Don't call ClusterDirConfigLoader._add_arguments as we don't want
         # its defaults on self.parser. Instead, we will put those on
         # default options on our subparsers.
         
         # This has all the common options that all subcommands use
         parent_parser1 = ArgumentParser(
             add_help=False,
             argument_default=SUPPRESS
         )
         self._add_ipython_dir(parent_parser1)
         self._add_log_level(parent_parser1)
 
         # This has all the common options that other subcommands use
         parent_parser2 = ArgumentParser(
             add_help=False,
             argument_default=SUPPRESS
         )
         self._add_cluster_profile(parent_parser2)
         self._add_cluster_dir(parent_parser2)
         self._add_work_dir(parent_parser2)
         paa = parent_parser2.add_argument
         paa('--log-to-file',
             action='store_true', dest='Global.log_to_file', 
             help='Log to a file in the log directory (default is stdout)')
 
         # Create the object used to create the subparsers.
         subparsers = self.parser.add_subparsers(
             dest='Global.subcommand',
             title='ipcluster subcommands',
             description=
             """ipcluster has a variety of subcommands. The general way of 
             running ipcluster is 'ipcluster <cmd> [options]'. To get help
             on a particular subcommand do 'ipcluster <cmd> -h'."""
             # help="For more help, type 'ipcluster <cmd> -h'",
         )
 
         # The "list" subcommand parser
         parser_list = subparsers.add_parser(
             'list',
             parents=[parent_parser1],
             argument_default=SUPPRESS,
             help="List all clusters in cwd and ipython_dir.",
             description=
             """List all available clusters, by cluster directory, that can
             be found in the current working directly or in the ipython
             directory. Cluster directories are named using the convention
             'cluster_<profile>'."""
         )
 
         # The "create" subcommand parser
         parser_create = subparsers.add_parser(
             'create',
             parents=[parent_parser1, parent_parser2],
             argument_default=SUPPRESS,
             help="Create a new cluster directory.",
             description=
             """Create an ipython cluster directory by its profile name or 
             cluster directory path. Cluster directories contain 
             configuration, log and security related files and are named 
             using the convention 'cluster_<profile>'. By default they are
             located in your ipython directory. Once created, you will
             probably need to edit the configuration files in the cluster
             directory to configure your cluster. Most users will create a
             cluster directory by profile name, 
             'ipcluster create -p mycluster', which will put the directory
             in '<ipython_dir>/cluster_mycluster'. 
             """
         )
         paa = parser_create.add_argument
         paa('--reset-config',
             dest='Global.reset_config', action='store_true',
             help=
             """Recopy the default config files to the cluster directory.
             You will loose any modifications you have made to these files.""")
 
         # The "start" subcommand parser
         parser_start = subparsers.add_parser(
             'start',
             parents=[parent_parser1, parent_parser2],
             argument_default=SUPPRESS,
             help="Start a cluster.",
             description=
             """Start an ipython cluster by its profile name or cluster 
             directory. Cluster directories contain configuration, log and
             security related files and are named using the convention
             'cluster_<profile>' and should be creating using the 'start'
             subcommand of 'ipcluster'. If your cluster directory is in 
             the cwd or the ipython directory, you can simply refer to it
             using its profile name, 'ipcluster start -n 4 -p <profile>`,
             otherwise use the '--cluster-dir' option.
             """
         )
         paa = parser_start.add_argument
         paa('-n', '--number',
             type=int, dest='Global.n',
             help='The number of engines to start.',
             metavar='Global.n')
         paa('--clean-logs',
             dest='Global.clean_logs', action='store_true',
             help='Delete old log flies before starting.')
         paa('--no-clean-logs',
             dest='Global.clean_logs', action='store_false',
             help="Don't delete old log flies before starting.")
         paa('--daemon',
             dest='Global.daemonize', action='store_true',
             help='Daemonize the ipcluster program. This implies --log-to-file')
         paa('--no-daemon',
             dest='Global.daemonize', action='store_false',
             help="Dont't daemonize the ipcluster program.")
 
         # The "stop" subcommand parser
         parser_stop = subparsers.add_parser(
             'stop',
             parents=[parent_parser1, parent_parser2],
             argument_default=SUPPRESS,
             help="Stop a running cluster.",
             description=
             """Stop a running ipython cluster by its profile name or cluster 
             directory. Cluster directories are named using the convention
             'cluster_<profile>'. If your cluster directory is in 
             the cwd or the ipython directory, you can simply refer to it
             using its profile name, 'ipcluster stop -p <profile>`, otherwise
             use the '--cluster-dir' option.
             """
         )
         paa = parser_stop.add_argument
         paa('--signal',
             dest='Global.signal', type=int,
             help="The signal number to use in stopping the cluster (default=2).",
             metavar="Global.signal")
 
 
 #-----------------------------------------------------------------------------
 # Main application
 #-----------------------------------------------------------------------------
 
 
 class IPClusterApp(ApplicationWithClusterDir):
 
     name = u'ipclusterz'
     description = _description
     usage = None
     command_line_loader = IPClusterAppConfigLoader
     default_config_file_name = default_config_file_name
     default_log_level = logging.INFO
     auto_create_cluster_dir = False
 
     def create_default_config(self):
         super(IPClusterApp, self).create_default_config()
         self.default_config.Global.controller_launcher = \
             'IPython.zmq.parallel.launcher.LocalControllerLauncher'
         self.default_config.Global.engine_launcher = \
             'IPython.zmq.parallel.launcher.LocalEngineSetLauncher'
         self.default_config.Global.n = 2
         self.default_config.Global.reset_config = False
         self.default_config.Global.clean_logs = True
         self.default_config.Global.signal = 2
         self.default_config.Global.daemonize = False
 
     def find_resources(self):
         subcommand = self.command_line_config.Global.subcommand
         if subcommand=='list':
             self.list_cluster_dirs()
             # Exit immediately because there is nothing left to do.
             self.exit()
         elif subcommand=='create':
             self.auto_create_cluster_dir = True
             super(IPClusterApp, self).find_resources()
         elif subcommand=='start' or subcommand=='stop':
             self.auto_create_cluster_dir = True
             try:
                 super(IPClusterApp, self).find_resources()
             except ClusterDirError:
                 raise ClusterDirError(
                     "Could not find a cluster directory. A cluster dir must "
                     "be created before running 'ipcluster start'.  Do "
                     "'ipcluster create -h' or 'ipcluster list -h' for more "
                     "information about creating and listing cluster dirs."
                 )
 
     def list_cluster_dirs(self):
         # Find the search paths
         cluster_dir_paths = os.environ.get('IPCLUSTER_DIR_PATH','')
         if cluster_dir_paths:
             cluster_dir_paths = cluster_dir_paths.split(':')
         else:
             cluster_dir_paths = []
         try:
             ipython_dir = self.command_line_config.Global.ipython_dir
         except AttributeError:
             ipython_dir = self.default_config.Global.ipython_dir
         paths = [os.getcwd(), ipython_dir] + \
             cluster_dir_paths
         paths = list(set(paths))
 
         self.log.info('Searching for cluster dirs in paths: %r' % paths)
         for path in paths:
             files = os.listdir(path)
             for f in files:
                 full_path = os.path.join(path, f)
                 if os.path.isdir(full_path) and f.startswith('cluster_'):
                     profile = full_path.split('_')[-1]
                     start_cmd = 'ipcluster start -p %s -n 4' % profile
                     print start_cmd + " ==> " + full_path
 
     def pre_construct(self):
         # IPClusterApp.pre_construct() is where we cd to the working directory.
         super(IPClusterApp, self).pre_construct()
         config = self.master_config
         try:
             daemon = config.Global.daemonize
             if daemon:
                 config.Global.log_to_file = True
         except AttributeError:
             pass
 
     def construct(self):
         config = self.master_config
         subcmd = config.Global.subcommand
         reset = config.Global.reset_config
         if subcmd == 'list':
             return
         if subcmd == 'create':
             self.log.info('Copying default config files to cluster directory '
             '[overwrite=%r]' % (reset,))
             self.cluster_dir_obj.copy_all_config_files(overwrite=reset)
         if subcmd =='start':
             self.cluster_dir_obj.copy_all_config_files(overwrite=False)
             self.start_logging()
             self.loop = ioloop.IOLoop.instance()
             # reactor.callWhenRunning(self.start_launchers)
             dc = ioloop.DelayedCallback(self.start_launchers, 0, self.loop)
             dc.start()
 
     def start_launchers(self):
         config = self.master_config
 
         # Create the launchers. In both bases, we set the work_dir of
         # the launcher to the cluster_dir. This is where the launcher's
         # subprocesses will be launched. It is not where the controller
         # and engine will be launched.
         el_class = import_item(config.Global.engine_launcher)
         self.engine_launcher = el_class(
-            work_dir=self.cluster_dir, config=config
+            work_dir=self.cluster_dir, config=config, logname=self.log.name
         )
         cl_class = import_item(config.Global.controller_launcher)
         self.controller_launcher = cl_class(
-            work_dir=self.cluster_dir, config=config
+            work_dir=self.cluster_dir, config=config,
+            logname=self.log.name
         )
 
         # Setup signals
         signal.signal(signal.SIGINT, self.sigint_handler)
 
         # Setup the observing of stopping. If the controller dies, shut
         # everything down as that will be completely fatal for the engines.
         self.controller_launcher.on_stop(self.stop_launchers)
         # d1.addCallback(self.stop_launchers)
         # But, we don't monitor the stopping of engines. An engine dying
         # is just fine and in principle a user could start a new engine.
         # Also, if we did monitor engine stopping, it is difficult to
         # know what to do when only some engines die. Currently, the
         # observing of engine stopping is inconsistent. Some launchers
         # might trigger on a single engine stopping, other wait until
         # all stop.  TODO: think more about how to handle this.
         
         # Start the controller and engines
         self._stopping = False  # Make sure stop_launchers is not called 2x.
         d = self.start_controller()
         self.start_engines()
         self.startup_message()
         # d.addCallback(self.start_engines)
         # d.addCallback(self.startup_message)
         # If the controller or engines fail to start, stop everything
         # d.addErrback(self.stop_launchers)
         return d
 
     def startup_message(self, r=None):
-        logging.info("IPython cluster: started")
+        self.log.info("IPython cluster: started")
         return r
         
     def start_controller(self, r=None):
-        # logging.info("In start_controller")
+        # self.log.info("In start_controller")
         config = self.master_config
         d = self.controller_launcher.start(
             cluster_dir=config.Global.cluster_dir
         )
         return d
             
     def start_engines(self, r=None):
-        # logging.info("In start_engines")
+        # self.log.info("In start_engines")
         config = self.master_config
         d = self.engine_launcher.start(
             config.Global.n,
             cluster_dir=config.Global.cluster_dir
         )
         return d
 
     def stop_controller(self, r=None):
-        # logging.info("In stop_controller")
+        # self.log.info("In stop_controller")
         if self.controller_launcher.running:
             return self.controller_launcher.stop()
 
     def stop_engines(self, r=None):
-        # logging.info("In stop_engines")
+        # self.log.info("In stop_engines")
         if self.engine_launcher.running:
             d = self.engine_launcher.stop()
             # d.addErrback(self.log_err)
             return d
         else:
             return None
 
     def log_err(self, f):
-        logging.error(f.getTraceback())
+        self.log.error(f.getTraceback())
         return None
         
     def stop_launchers(self, r=None):
         if not self._stopping:
             self._stopping = True
             # if isinstance(r, failure.Failure):
-            #     logging.error('Unexpected error in ipcluster:')
-            #     logging.info(r.getTraceback())
-            logging.error("IPython cluster: stopping")
+            #     self.log.error('Unexpected error in ipcluster:')
+            #     self.log.info(r.getTraceback())
+            self.log.error("IPython cluster: stopping")
             # These return deferreds. We are not doing anything with them
             # but we are holding refs to them as a reminder that they 
             # do return deferreds.
             d1 = self.stop_engines()
             d2 = self.stop_controller()
             # Wait a few seconds to let things shut down.
             dc = ioloop.DelayedCallback(self.loop.stop, 4000, self.loop)
             dc.start()
             # reactor.callLater(4.0, reactor.stop)
 
     def sigint_handler(self, signum, frame):
         self.stop_launchers()
         
     def start_logging(self):
         # Remove old log files of the controller and engine
         if self.master_config.Global.clean_logs:
             log_dir = self.master_config.Global.log_dir
             for f in os.listdir(log_dir):
                 if f.startswith('ipengine' + '-'):
                     if f.endswith('.log') or f.endswith('.out') or f.endswith('.err'):
                         os.remove(os.path.join(log_dir, f))
                 if f.startswith('ipcontroller' + '-'):
                     if f.endswith('.log') or f.endswith('.out') or f.endswith('.err'):
                         os.remove(os.path.join(log_dir, f))
         # This will remote old log files for ipcluster itself
         super(IPClusterApp, self).start_logging()
 
     def start_app(self):
         """Start the application, depending on what subcommand is used."""
         subcmd = self.master_config.Global.subcommand
         if subcmd=='create' or subcmd=='list':
             return
         elif subcmd=='start':
             self.start_app_start()
         elif subcmd=='stop':
             self.start_app_stop()
 
     def start_app_start(self):
         """Start the app for the start subcommand."""
         config = self.master_config
         # First see if the cluster is already running
         try:
             pid = self.get_pid_from_file()
         except PIDFileError:
             pass
         else:
             self.log.critical(
                 'Cluster is already running with [pid=%s]. '
                 'use "ipcluster stop" to stop the cluster.' % pid
             )
             # Here I exit with a unusual exit status that other processes
             # can watch for to learn how I existed.
             self.exit(ALREADY_STARTED)
 
         # Now log and daemonize
         self.log.info(
             'Starting ipcluster with [daemon=%r]' % config.Global.daemonize
         )
         # TODO: Get daemonize working on Windows or as a Windows Server.
         if config.Global.daemonize:
             if os.name=='posix':
                 from twisted.scripts._twistd_unix import daemonize
                 daemonize()
 
         # Now write the new pid file AFTER our new forked pid is active.
         self.write_pid_file()
         try:
             self.loop.start()
         except:
-            logging.info("stopping...")
+            self.log.info("stopping...")
         self.remove_pid_file()
 
     def start_app_stop(self):
         """Start the app for the stop subcommand."""
         config = self.master_config
         try:
             pid = self.get_pid_from_file()
         except PIDFileError:
             self.log.critical(
                 'Problem reading pid file, cluster is probably not running.'
             )
             # Here I exit with a unusual exit status that other processes
             # can watch for to learn how I existed.
             self.exit(ALREADY_STOPPED)
         else:
             if os.name=='posix':
                 sig = config.Global.signal
                 self.log.info(
                     "Stopping cluster [pid=%r] with [signal=%r]" % (pid, sig)
                 )
                 os.kill(pid, sig)
             elif os.name=='nt':
                 # As of right now, we don't support daemonize on Windows, so
                 # stop will not do anything. Minimally, it should clean up the
                 # old .pid files.
                 self.remove_pid_file()
 
 
 def launch_new_instance():
     """Create and run the IPython cluster."""
     app = IPClusterApp()
     app.start()
 
 
 if __name__ == '__main__':
     launch_new_instance()
 

IPython/zmq/parallel/ipcontrollerapp.py

@@ -1,340 +1,340 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 The IPython controller application.
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 from __future__ import with_statement
 
 import copy
 import sys
 import os
 import logging
 # from twisted.application import service
 # from twisted.internet import reactor
 # from twisted.python import log
 
 import zmq
 from zmq.log.handlers import PUBHandler
 
 from IPython.config.loader import Config
 from IPython.zmq.parallel import factory
 from IPython.zmq.parallel.controller import ControllerFactory
 from IPython.zmq.parallel.clusterdir import (
     ApplicationWithClusterDir,
     ClusterDirConfigLoader
 )
 # from IPython.kernel.fcutil import FCServiceFactory, FURLError
 from IPython.utils.traitlets import Instance, Unicode
 
 from entry_point import generate_exec_key
 
 
 #-----------------------------------------------------------------------------
 # Module level variables
 #-----------------------------------------------------------------------------
 
 
 #: The default config file name for this application
 default_config_file_name = u'ipcontroller_config.py'
 
 
 _description = """Start the IPython controller for parallel computing.
 
 The IPython controller provides a gateway between the IPython engines and
 clients. The controller needs to be started before the engines and can be
 configured using command line options or using a cluster directory. Cluster
 directories contain config, log and security files and are usually located in
 your .ipython directory and named as "cluster_<profile>". See the --profile
 and --cluster-dir options for details.
 """
 
 #-----------------------------------------------------------------------------
 # Default interfaces
 #-----------------------------------------------------------------------------
 
 # The default client interfaces for FCClientServiceFactory.interfaces
 default_client_interfaces = Config()
 default_client_interfaces.Default.url_file = 'ipcontroller-client.url'
 
 # Make this a dict we can pass to Config.__init__ for the default
 default_client_interfaces = dict(copy.deepcopy(default_client_interfaces.items()))
 
 
 
 # The default engine interfaces for FCEngineServiceFactory.interfaces
 default_engine_interfaces = Config()
 default_engine_interfaces.Default.url_file = u'ipcontroller-engine.url'
 
 # Make this a dict we can pass to Config.__init__ for the default
 default_engine_interfaces = dict(copy.deepcopy(default_engine_interfaces.items()))
 
 
 #-----------------------------------------------------------------------------
 # Service factories
 #-----------------------------------------------------------------------------
 
 # 
 # class FCClientServiceFactory(FCServiceFactory):
 #     """A Foolscap implementation of the client services."""
 # 
 #     cert_file = Unicode(u'ipcontroller-client.pem', config=True)
 #     interfaces = Instance(klass=Config, kw=default_client_interfaces,
 #                           allow_none=False, config=True)
 # 
 # 
 # class FCEngineServiceFactory(FCServiceFactory):
 #     """A Foolscap implementation of the engine services."""
 # 
 #     cert_file = Unicode(u'ipcontroller-engine.pem', config=True)
 #     interfaces = Instance(klass=dict, kw=default_engine_interfaces,
 #                           allow_none=False, config=True)
 # 
 
 #-----------------------------------------------------------------------------
 # Command line options
 #-----------------------------------------------------------------------------
 
 
 class IPControllerAppConfigLoader(ClusterDirConfigLoader):
 
     def _add_arguments(self):
         super(IPControllerAppConfigLoader, self)._add_arguments()
         paa = self.parser.add_argument
         
         ## Hub Config:
         paa('--mongodb', 
             dest='HubFactory.db_class', action='store_const',
             const='IPython.zmq.parallel.mongodb.MongoDB', 
             help='Use MongoDB task storage [default: in-memory]')
         paa('--hb',
             type=int, dest='HubFactory.hb', nargs=2,
             help='The (2) ports the Hub\'s Heartmonitor will use for the heartbeat '
             'connections [default: random]',
             metavar='Hub.hb_ports')
         paa('--ping',
             type=int, dest='HubFactory.ping',
             help='The frequency at which the Hub pings the engines for heartbeats '
             ' (in ms) [default: 100]',
             metavar='Hub.ping')
         
         # Client config
         paa('--client-ip',
             type=str, dest='HubFactory.client_ip', 
             help='The IP address or hostname the Hub will listen on for '
             'client connections. Both engine-ip and client-ip can be set simultaneously '
             'via --ip [default: loopback]',
             metavar='Hub.client_ip')
         paa('--client-transport',
             type=str, dest='HubFactory.client_transport', 
             help='The ZeroMQ transport the Hub will use for '
             'client connections. Both engine-transport and client-transport can be set simultaneously '
             'via --transport [default: tcp]',
             metavar='Hub.client_transport')
         paa('--query',
             type=int, dest='HubFactory.query_port', 
             help='The port on which the Hub XREP socket will listen for result queries from clients [default: random]',
             metavar='Hub.query_port')
         paa('--notifier',
             type=int, dest='HubFactory.notifier_port', 
             help='The port on which the Hub PUB socket will listen for notification connections [default: random]',
             metavar='Hub.notifier_port')
         
         # Engine config
         paa('--engine-ip',
             type=str, dest='HubFactory.engine_ip', 
             help='The IP address or hostname the Hub will listen on for '
             'engine connections. This applies to the Hub and its schedulers'
             'engine-ip and client-ip can be set simultaneously '
             'via --ip [default: loopback]',
             metavar='Hub.engine_ip')
         paa('--engine-transport',
             type=str, dest='HubFactory.engine_transport', 
             help='The ZeroMQ transport the Hub will use for '
             'client connections. Both engine-transport and client-transport can be set simultaneously '
             'via --transport [default: tcp]',
             metavar='Hub.engine_transport')
         
         # Scheduler config
         paa('--mux',
             type=int, dest='ControllerFactory.mux', nargs=2,
             help='The (2) ports the MUX scheduler will listen on for client,engine '
             'connections, respectively [default: random]',
             metavar='Scheduler.mux_ports')
         paa('--task',
             type=int, dest='ControllerFactory.task', nargs=2,
             help='The (2) ports the Task scheduler will listen on for client,engine '
             'connections, respectively [default: random]',
             metavar='Scheduler.task_ports')
         paa('--control',
             type=int, dest='ControllerFactory.control', nargs=2,
             help='The (2) ports the Control scheduler will listen on for client,engine '
             'connections, respectively [default: random]',
             metavar='Scheduler.control_ports')
         paa('--iopub',
             type=int, dest='ControllerFactory.iopub', nargs=2,
             help='The (2) ports the IOPub scheduler will listen on for client,engine '
             'connections, respectively [default: random]',
             metavar='Scheduler.iopub_ports')
         paa('--scheme',
             type=str, dest='ControllerFactory.scheme',
             choices = ['pure', 'lru', 'plainrandom', 'weighted', 'twobin','leastload'],
             help='select the task scheduler scheme  [default: Python LRU]',
             metavar='Scheduler.scheme')
         paa('--usethreads',
             dest='ControllerFactory.usethreads', action="store_true",
             help='Use threads instead of processes for the schedulers',
             )
         
         ## Global config
         paa('--log-to-file',
             action='store_true', dest='Global.log_to_file',
             help='Log to a file in the log directory (default is stdout)')
         paa('--log-url',
             type=str, dest='Global.log_url',
             help='Broadcast logs to an iploggerz process [default: disabled]')
         paa('-r','--reuse-key', 
             action='store_true', dest='Global.reuse_key',
             help='Try to reuse existing execution keys.')
         paa('--no-secure',
             action='store_false', dest='Global.secure',
             help='Turn off execution keys (default).')
         paa('--secure',
             action='store_true', dest='Global.secure',
             help='Turn on execution keys.')
         paa('--execkey',
             type=str, dest='Global.exec_key',
             help='path to a file containing an execution key.',
             metavar='keyfile')
         factory.add_session_arguments(self.parser)
         factory.add_registration_arguments(self.parser)
 
 
 #-----------------------------------------------------------------------------
 # The main application
 #-----------------------------------------------------------------------------
 
 
 class IPControllerApp(ApplicationWithClusterDir):
 
     name = u'ipcontrollerz'
     description = _description
     command_line_loader = IPControllerAppConfigLoader
     default_config_file_name = default_config_file_name
     auto_create_cluster_dir = True
 
     def create_default_config(self):
         super(IPControllerApp, self).create_default_config()
         # Don't set defaults for Global.secure or Global.reuse_furls
         # as those are set in a component.
         self.default_config.Global.import_statements = []
         self.default_config.Global.clean_logs = True
         self.default_config.Global.secure = False
         self.default_config.Global.reuse_key = False
         self.default_config.Global.exec_key = "exec_key.key"
 
     def pre_construct(self):
         super(IPControllerApp, self).pre_construct()
         c = self.master_config
         # The defaults for these are set in FCClientServiceFactory and
         # FCEngineServiceFactory, so we only set them here if the global
         # options have be set to override the class level defaults.
         
         # if hasattr(c.Global, 'reuse_furls'):
         #     c.FCClientServiceFactory.reuse_furls = c.Global.reuse_furls
         #     c.FCEngineServiceFactory.reuse_furls = c.Global.reuse_furls
         #     del c.Global.reuse_furls
         # if hasattr(c.Global, 'secure'):
         #     c.FCClientServiceFactory.secure = c.Global.secure
         #     c.FCEngineServiceFactory.secure = c.Global.secure
         #     del c.Global.secure
 
     def construct(self):
         # This is the working dir by now.
         sys.path.insert(0, '')
         c = self.master_config
         
         self.import_statements()
 
         if c.Global.secure:
             keyfile = os.path.join(c.Global.security_dir, c.Global.exec_key)
             if not c.Global.reuse_key or not os.path.exists(keyfile):
                 generate_exec_key(keyfile)
             c.SessionFactory.exec_key = keyfile
         else:
             keyfile = os.path.join(c.Global.security_dir, c.Global.exec_key)
             if os.path.exists(keyfile):
                 os.remove(keyfile)
             c.SessionFactory.exec_key = ''
         
         try:
-            self.factory = ControllerFactory(config=c)
+            self.factory = ControllerFactory(config=c, logname=self.log.name)
             self.start_logging()
             self.factory.construct()
         except:
             self.log.error("Couldn't construct the Controller", exc_info=True)
             self.exit(1)
     
     def save_urls(self):
         """save the registration urls to files."""
         c = self.master_config
         
         sec_dir = c.Global.security_dir
         cf = self.factory
         
         with open(os.path.join(sec_dir, 'ipcontroller-engine.url'), 'w') as f:
             f.write("%s://%s:%s"%(cf.engine_transport, cf.engine_ip, cf.regport))
         
         with open(os.path.join(sec_dir, 'ipcontroller-client.url'), 'w') as f:
             f.write("%s://%s:%s"%(cf.client_transport, cf.client_ip, cf.regport))
         
     
     def import_statements(self):
         statements = self.master_config.Global.import_statements
         for s in statements:
             try:
                 self.log.msg("Executing statement: '%s'" % s)
                 exec s in globals(), locals()
             except:
                 self.log.msg("Error running statement: %s" % s)
 
     def start_logging(self):
         super(IPControllerApp, self).start_logging()
         if self.master_config.Global.log_url:
             context = self.factory.context
             lsock = context.socket(zmq.PUB)
             lsock.connect(self.master_config.Global.log_url)
             handler = PUBHandler(lsock)
             handler.root_topic = 'controller'
             handler.setLevel(self.log_level)
             self.log.addHandler(handler)
     # 
     def start_app(self):
         # Start the subprocesses:
         self.factory.start()
         self.write_pid_file(overwrite=True)
         try:
             self.factory.loop.start()
         except KeyboardInterrupt:
             self.log.critical("Interrupted, Exiting...\n")
 
 
 def launch_new_instance():
     """Create and run the IPython controller"""
     app = IPControllerApp()
     app.start()
 
 
 if __name__ == '__main__':
     launch_new_instance()

IPython/zmq/parallel/ipengineapp.py

@@ -1,261 +1,261 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 The IPython engine application
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import os
 import sys
 
 import zmq
 from zmq.eventloop import ioloop
 
 from IPython.zmq.parallel.clusterdir import (
     ApplicationWithClusterDir,
     ClusterDirConfigLoader
 )
 from IPython.zmq.log import EnginePUBHandler
 
 from IPython.zmq.parallel import factory
 from IPython.zmq.parallel.engine import EngineFactory
 from IPython.zmq.parallel.streamkernel import Kernel
 from IPython.utils.importstring import import_item
 
 #-----------------------------------------------------------------------------
 # Module level variables
 #-----------------------------------------------------------------------------
 
 #: The default config file name for this application
 default_config_file_name = u'ipengine_config.py'
 
 
 mpi4py_init = """from mpi4py import MPI as mpi
 mpi.size = mpi.COMM_WORLD.Get_size()
 mpi.rank = mpi.COMM_WORLD.Get_rank()
 """
 
 
 pytrilinos_init = """from PyTrilinos import Epetra
 class SimpleStruct:
 pass
 mpi = SimpleStruct()
 mpi.rank = 0
 mpi.size = 0
 """
 
 
 _description = """Start an IPython engine for parallel computing.\n\n
 
 IPython engines run in parallel and perform computations on behalf of a client
 and controller. A controller needs to be started before the engines. The
 engine can be configured using command line options or using a cluster
 directory. Cluster directories contain config, log and security files and are
 usually located in your .ipython directory and named as "cluster_<profile>".
 See the --profile and --cluster-dir options for details.
 """
 
 #-----------------------------------------------------------------------------
 # Command line options
 #-----------------------------------------------------------------------------
 
 
 class IPEngineAppConfigLoader(ClusterDirConfigLoader):
 
     def _add_arguments(self):
         super(IPEngineAppConfigLoader, self)._add_arguments()
         paa = self.parser.add_argument
         # Controller config
         paa('--url-file',
             type=unicode, dest='Global.url_file',
             help='The full location of the file containing the FURL of the '
             'controller. If this is not given, the FURL file must be in the '
             'security directory of the cluster directory.  This location is '
             'resolved using the --profile and --app-dir options.',
             metavar='Global.url_file')
         # MPI
         paa('--mpi',
             type=str, dest='MPI.use',
             help='How to enable MPI (mpi4py, pytrilinos, or empty string to disable).',
             metavar='MPI.use')
         # Global config
         paa('--log-to-file',
             action='store_true', dest='Global.log_to_file',
             help='Log to a file in the log directory (default is stdout)')
         paa('--log-url',
             dest='Global.log_url',
             help="url of ZMQ logger, as started with iploggerz")
         paa('--execkey',
             type=str, dest='Global.exec_key',
             help='path to a file containing an execution key.',
             metavar='keyfile')
         paa('--no-secure',
             action='store_false', dest='Global.secure',
             help='Turn off execution keys.')
         paa('--secure',
             action='store_true', dest='Global.secure',
             help='Turn on execution keys (default).')
         # init command
         paa('-c',
             type=str, dest='Global.extra_exec_lines',
             help='specify a command to be run at startup')
         
         factory.add_session_arguments(self.parser)
         factory.add_registration_arguments(self.parser)
 
 
 #-----------------------------------------------------------------------------
 # Main application
 #-----------------------------------------------------------------------------
 
 
 class IPEngineApp(ApplicationWithClusterDir):
 
     name = u'ipenginez'
     description = _description
     command_line_loader = IPEngineAppConfigLoader
     default_config_file_name = default_config_file_name
     auto_create_cluster_dir = True
 
     def create_default_config(self):
         super(IPEngineApp, self).create_default_config()
 
         # The engine should not clean logs as we don't want to remove the
         # active log files of other running engines.
         self.default_config.Global.clean_logs = False
         self.default_config.Global.secure = True
 
         # Global config attributes
         self.default_config.Global.exec_lines = []
         self.default_config.Global.extra_exec_lines = ''
 
         # Configuration related to the controller
         # This must match the filename (path not included) that the controller
         # used for the FURL file.
         self.default_config.Global.url = u'tcp://localhost:10101'
         # If given, this is the actual location of the controller's FURL file.
         # If not, this is computed using the profile, app_dir and furl_file_name
         self.default_config.Global.key_file_name = u'exec_key.key'
         self.default_config.Global.key_file = u''
 
         # MPI related config attributes
         self.default_config.MPI.use = ''
         self.default_config.MPI.mpi4py = mpi4py_init
         self.default_config.MPI.pytrilinos = pytrilinos_init
 
     def post_load_command_line_config(self):
         pass
 
     def pre_construct(self):
         super(IPEngineApp, self).pre_construct()
         # self.find_cont_url_file()
         self.find_key_file()
         if self.master_config.Global.extra_exec_lines:
             self.master_config.Global.exec_lines.append(self.master_config.Global.extra_exec_lines)
 
     def find_key_file(self):
         """Set the key file.
 
         Here we don't try to actually see if it exists for is valid as that
         is hadled by the connection logic.
         """
         config = self.master_config
         # Find the actual controller key file
         if not config.Global.key_file:
             try_this = os.path.join(
                 config.Global.cluster_dir, 
                 config.Global.security_dir,
                 config.Global.key_file_name
             )
             config.Global.key_file = try_this
         
     def construct(self):
         # This is the working dir by now.
         sys.path.insert(0, '')
         config = self.master_config
         if os.path.exists(config.Global.key_file) and config.Global.secure:
             config.SessionFactory.exec_key = config.Global.key_file
         
         config.Kernel.exec_lines = config.Global.exec_lines
 
         self.start_mpi()
 
         # Create the underlying shell class and EngineService
         # shell_class = import_item(self.master_config.Global.shell_class)
         try:
-            self.engine = EngineFactory(config=config)
+            self.engine = EngineFactory(config=config, logname=self.log.name)
         except:
             self.log.error("Couldn't start the Engine", exc_info=True)
             self.exit(1)
         
         self.start_logging()
 
         # Create the service hierarchy
         # self.main_service = service.MultiService()
         # self.engine_service.setServiceParent(self.main_service)
         # self.tub_service = Tub()
         # self.tub_service.setServiceParent(self.main_service)
         # # This needs to be called before the connection is initiated
         # self.main_service.startService()
 
         # This initiates the connection to the controller and calls
         # register_engine to tell the controller we are ready to do work
         # self.engine_connector = EngineConnector(self.tub_service)
 
         # self.log.info("Using furl file: %s" % self.master_config.Global.furl_file)
 
         # reactor.callWhenRunning(self.call_connect)
 
 
     def start_logging(self):
         super(IPEngineApp, self).start_logging()
         if self.master_config.Global.log_url:
             context = self.engine.context
             lsock = context.socket(zmq.PUB)
             lsock.connect(self.master_config.Global.log_url)
             handler = EnginePUBHandler(self.engine, lsock)
             handler.setLevel(self.log_level)
             self.log.addHandler(handler)
     
     def start_mpi(self):
         global mpi
         mpikey = self.master_config.MPI.use
         mpi_import_statement = self.master_config.MPI.get(mpikey, None)
         if mpi_import_statement is not None:
             try:
                 self.log.info("Initializing MPI:")
                 self.log.info(mpi_import_statement)
                 exec mpi_import_statement in globals()
             except:
                 mpi = None
         else:
             mpi = None
 
 
     def start_app(self):
         self.engine.start()
         try:
             self.engine.loop.start()
         except KeyboardInterrupt:
             self.log.critical("Engine Interrupted, shutting down...\n")
 
 
 def launch_new_instance():
     """Create and run the IPython controller"""
     app = IPEngineApp()
     app.start()
 
 
 if __name__ == '__main__':
     launch_new_instance()
 

IPython/zmq/parallel/iploggerapp.py

@@ -1,131 +1,132 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 A simple IPython logger application
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2011  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import os
 import sys
 
 import zmq
 
 from IPython.zmq.parallel.clusterdir import (
     ApplicationWithClusterDir,
     ClusterDirConfigLoader
 )
 from IPython.zmq.parallel.logwatcher import LogWatcher
 
 #-----------------------------------------------------------------------------
 # Module level variables
 #-----------------------------------------------------------------------------
 
 #: The default config file name for this application
 default_config_file_name = u'iplogger_config.py'
 
 _description = """Start an IPython logger for parallel computing.\n\n
 
 IPython controllers and engines (and your own processes) can broadcast log messages
 by registering a `zmq.log.handlers.PUBHandler` with the `logging` module. The
 logger can be configured using command line options or using a cluster
 directory. Cluster directories contain config, log and security files and are
 usually located in your .ipython directory and named as "cluster_<profile>".
 See the --profile and --cluster-dir options for details.
 """
 
 #-----------------------------------------------------------------------------
 # Command line options
 #-----------------------------------------------------------------------------
 
 
 class IPLoggerAppConfigLoader(ClusterDirConfigLoader):
 
     def _add_arguments(self):
         super(IPLoggerAppConfigLoader, self)._add_arguments()
         paa = self.parser.add_argument
         # Controller config
         paa('--url',
             type=str, dest='LogWatcher.url',
             help='The url the LogWatcher will listen on',
             )
         # MPI
         paa('--topics',
             type=str, dest='LogWatcher.topics', nargs='+',
             help='What topics to subscribe to',
             metavar='topics')
         # Global config
         paa('--log-to-file',
             action='store_true', dest='Global.log_to_file',
             help='Log to a file in the log directory (default is stdout)')
         
 
 #-----------------------------------------------------------------------------
 # Main application
 #-----------------------------------------------------------------------------
 
 
 class IPLoggerApp(ApplicationWithClusterDir):
 
     name = u'iploggerz'
     description = _description
     command_line_loader = IPLoggerAppConfigLoader
     default_config_file_name = default_config_file_name
     auto_create_cluster_dir = True
 
     def create_default_config(self):
         super(IPLoggerApp, self).create_default_config()
 
         # The engine should not clean logs as we don't want to remove the
         # active log files of other running engines.
         self.default_config.Global.clean_logs = False
 
         # If given, this is the actual location of the logger's URL file.
         # If not, this is computed using the profile, app_dir and furl_file_name
         self.default_config.Global.url_file_name = u'iplogger.url'
         self.default_config.Global.url_file = u''
 
     def post_load_command_line_config(self):
         pass
 
     def pre_construct(self):
         super(IPLoggerApp, self).pre_construct()
 
     def construct(self):
         # This is the working dir by now.
         sys.path.insert(0, '')
 
         self.start_logging()
 
         try:
-            self.watcher = LogWatcher(config=self.master_config)
+            self.watcher = LogWatcher(config=self.master_config, logname=self.log.name)
         except:
             self.log.error("Couldn't start the LogWatcher", exc_info=True)
             self.exit(1)
         
 
     def start_app(self):
         try:
+            self.watcher.start()
             self.watcher.loop.start()
         except KeyboardInterrupt:
             self.log.critical("Logging Interrupted, shutting down...\n")
 
 
 def launch_new_instance():
     """Create and run the IPython LogWatcher"""
     app = IPLoggerApp()
     app.start()
 
 
 if __name__ == '__main__':
     launch_new_instance()
 

IPython/zmq/parallel/launcher.py

@@ -1,824 +1,825 b''
 #!/usr/bin/env python
 # encoding: utf-8
 """
 Facilities for launching IPython processes asynchronously.
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2009  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import os
 import re
 import sys
 import logging
 
 from signal import SIGINT
 try:
     from signal import SIGKILL
 except ImportError:
     SIGKILL=SIGTERM
 
 from subprocess import Popen, PIPE
 
 from zmq.eventloop import ioloop
 
-from IPython.config.configurable import Configurable
+# from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import Str, Int, List, Unicode, Instance
 from IPython.utils.path import get_ipython_module_path
 from IPython.utils.process import find_cmd, pycmd2argv, FindCmdError
 
+from factory import LoggingFactory
 # from IPython.kernel.winhpcjob import (
 #     IPControllerTask, IPEngineTask,
 #     IPControllerJob, IPEngineSetJob
 # )
 
 
 #-----------------------------------------------------------------------------
 # Paths to the kernel apps
 #-----------------------------------------------------------------------------
 
 
 ipcluster_cmd_argv = pycmd2argv(get_ipython_module_path(
     'IPython.zmq.parallel.ipclusterapp'
 ))
 
 ipengine_cmd_argv = pycmd2argv(get_ipython_module_path(
     'IPython.zmq.parallel.ipengineapp'
 ))
 
 ipcontroller_cmd_argv = pycmd2argv(get_ipython_module_path(
     'IPython.zmq.parallel.ipcontrollerapp'
 ))
 
 #-----------------------------------------------------------------------------
 # Base launchers and errors
 #-----------------------------------------------------------------------------
 
 
 class LauncherError(Exception):
     pass
 
 
 class ProcessStateError(LauncherError):
     pass
 
 
 class UnknownStatus(LauncherError):
     pass
 
 
-class BaseLauncher(Configurable):
+class BaseLauncher(LoggingFactory):
     """An asbtraction for starting, stopping and signaling a process."""
 
     # In all of the launchers, the work_dir is where child processes will be
     # run. This will usually be the cluster_dir, but may not be. any work_dir
     # passed into the __init__ method will override the config value.
     # This should not be used to set the work_dir for the actual engine
     # and controller. Instead, use their own config files or the
     # controller_args, engine_args attributes of the launchers to add
     # the --work-dir option.
     work_dir = Unicode(u'.')
     loop = Instance('zmq.eventloop.ioloop.IOLoop')
     def _loop_default(self):
         return ioloop.IOLoop.instance()
 
-    def __init__(self, work_dir=u'.', config=None):
-        super(BaseLauncher, self).__init__(work_dir=work_dir, config=config)
+    def __init__(self, work_dir=u'.', config=None, **kwargs):
+        super(BaseLauncher, self).__init__(work_dir=work_dir, config=config, **kwargs)
         self.state = 'before' # can be before, running, after
         self.stop_callbacks = []
         self.start_data = None
         self.stop_data = None
 
     @property
     def args(self):
         """A list of cmd and args that will be used to start the process.
 
         This is what is passed to :func:`spawnProcess` and the first element
         will be the process name.
         """
         return self.find_args()
 
     def find_args(self):
         """The ``.args`` property calls this to find the args list.
 
         Subcommand should implement this to construct the cmd and args.
         """
         raise NotImplementedError('find_args must be implemented in a subclass')
 
     @property
     def arg_str(self):
         """The string form of the program arguments."""
         return ' '.join(self.args)
 
     @property
     def running(self):
         """Am I running."""
         if self.state == 'running':
             return True
         else:
             return False
 
     def start(self):
         """Start the process.
 
         This must return a deferred that fires with information about the
         process starting (like a pid, job id, etc.).
         """
         raise NotImplementedError('start must be implemented in a subclass')
 
     def stop(self):
         """Stop the process and notify observers of stopping.
 
         This must return a deferred that fires with information about the
         processing stopping, like errors that occur while the process is
         attempting to be shut down. This deferred won't fire when the process
         actually stops. To observe the actual process stopping, see
         :func:`observe_stop`.
         """
         raise NotImplementedError('stop must be implemented in a subclass')
 
     def on_stop(self, f):
         """Get a deferred that will fire when the process stops.
 
         The deferred will fire with data that contains information about
         the exit status of the process.
         """
         if self.state=='after':
             return f(self.stop_data)
         else:
             self.stop_callbacks.append(f)
 
     def notify_start(self, data):
         """Call this to trigger startup actions.
 
         This logs the process startup and sets the state to 'running'.  It is
         a pass-through so it can be used as a callback.
         """
 
-        logging.info('Process %r started: %r' % (self.args[0], data))
+        self.log.info('Process %r started: %r' % (self.args[0], data))
         self.start_data = data
         self.state = 'running'
         return data
 
     def notify_stop(self, data):
         """Call this to trigger process stop actions.
 
         This logs the process stopping and sets the state to 'after'. Call
         this to trigger all the deferreds from :func:`observe_stop`."""
 
-        logging.info('Process %r stopped: %r' % (self.args[0], data))
+        self.log.info('Process %r stopped: %r' % (self.args[0], data))
         self.stop_data = data
         self.state = 'after'
         for i in range(len(self.stop_callbacks)):
             d = self.stop_callbacks.pop()
             d(data)
         return data
 
     def signal(self, sig):
         """Signal the process.
 
         Return a semi-meaningless deferred after signaling the process.
 
         Parameters
         ----------
         sig : str or int
             'KILL', 'INT', etc., or any signal number
         """
         raise NotImplementedError('signal must be implemented in a subclass')
 
 
 #-----------------------------------------------------------------------------
 # Local process launchers
 #-----------------------------------------------------------------------------
 
 
 class LocalProcessLauncher(BaseLauncher):
     """Start and stop an external process in an asynchronous manner.
 
     This will launch the external process with a working directory of
     ``self.work_dir``.
     """
 
     # This is used to to construct self.args, which is passed to 
     # spawnProcess.
     cmd_and_args = List([])
     poll_frequency = Int(100) # in ms
 
-    def __init__(self, work_dir=u'.', config=None):
+    def __init__(self, work_dir=u'.', config=None, **kwargs):
         super(LocalProcessLauncher, self).__init__(
-            work_dir=work_dir, config=config
+            work_dir=work_dir, config=config, **kwargs
         )
         self.process = None
         self.start_deferred = None
         self.poller = None
 
     def find_args(self):
         return self.cmd_and_args
 
     def start(self):
         if self.state == 'before':
             self.process = Popen(self.args,
                 stdout=PIPE,stderr=PIPE,stdin=PIPE,
                 env=os.environ,
                 cwd=self.work_dir
             )
             
             self.loop.add_handler(self.process.stdout.fileno(), self.handle_stdout, self.loop.READ)
             self.loop.add_handler(self.process.stderr.fileno(), self.handle_stderr, self.loop.READ)
             self.poller = ioloop.PeriodicCallback(self.poll, self.poll_frequency, self.loop)
             self.poller.start()
             self.notify_start(self.process.pid)
         else:
             s = 'The process was already started and has state: %r' % self.state
             raise ProcessStateError(s)
 
     def stop(self):
         return self.interrupt_then_kill()
 
     def signal(self, sig):
         if self.state == 'running':
             self.process.send_signal(sig)
 
     def interrupt_then_kill(self, delay=2.0):
         """Send INT, wait a delay and then send KILL."""
         self.signal(SIGINT)
         self.killer  = ioloop.DelayedCallback(lambda : self.signal(SIGKILL), delay*1000, self.loop)
         self.killer.start()
 
     # callbacks, etc:
     
     def handle_stdout(self, fd, events):
         line = self.process.stdout.readline()
         # a stopped process will be readable but return empty strings
         if line:
-            logging.info(line[:-1])
+            self.log.info(line[:-1])
         else:
             self.poll()
     
     def handle_stderr(self, fd, events):
         line = self.process.stderr.readline()
         # a stopped process will be readable but return empty strings
         if line:
-            logging.error(line[:-1])
+            self.log.error(line[:-1])
         else:
             self.poll()
     
     def poll(self):
         status = self.process.poll()
         if status is not None:
             self.poller.stop()
             self.loop.remove_handler(self.process.stdout.fileno())
             self.loop.remove_handler(self.process.stderr.fileno())
             self.notify_stop(dict(exit_code=status, pid=self.process.pid))
         return status
 
 class LocalControllerLauncher(LocalProcessLauncher):
     """Launch a controller as a regular external process."""
 
     controller_cmd = List(ipcontroller_cmd_argv, config=True)
     # Command line arguments to ipcontroller.
     controller_args = List(['--log-to-file','--log-level', str(logging.ERROR)], config=True)
 
     def find_args(self):
         return self.controller_cmd + self.controller_args
 
     def start(self, cluster_dir):
         """Start the controller by cluster_dir."""
         self.controller_args.extend(['--cluster-dir', cluster_dir])
         self.cluster_dir = unicode(cluster_dir)
-        logging.info("Starting LocalControllerLauncher: %r" % self.args)
+        self.log.info("Starting LocalControllerLauncher: %r" % self.args)
         return super(LocalControllerLauncher, self).start()
 
 
 class LocalEngineLauncher(LocalProcessLauncher):
     """Launch a single engine as a regular externall process."""
 
     engine_cmd = List(ipengine_cmd_argv, config=True)
     # Command line arguments for ipengine.
     engine_args = List(
         ['--log-to-file','--log-level', str(logging.ERROR)], config=True
     )
 
     def find_args(self):
         return self.engine_cmd + self.engine_args
 
     def start(self, cluster_dir):
         """Start the engine by cluster_dir."""
         self.engine_args.extend(['--cluster-dir', cluster_dir])
         self.cluster_dir = unicode(cluster_dir)
         return super(LocalEngineLauncher, self).start()
 
 
 class LocalEngineSetLauncher(BaseLauncher):
     """Launch a set of engines as regular external processes."""
 
     # Command line arguments for ipengine.
     engine_args = List(
         ['--log-to-file','--log-level', str(logging.ERROR)], config=True
     )
     # launcher class
     launcher_class = LocalEngineLauncher
     
-    def __init__(self, work_dir=u'.', config=None):
+    def __init__(self, work_dir=u'.', config=None, **kwargs):
         super(LocalEngineSetLauncher, self).__init__(
-            work_dir=work_dir, config=config
+            work_dir=work_dir, config=config, **kwargs
         )
         self.launchers = {}
         self.stop_data = {}
 
     def start(self, n, cluster_dir):
         """Start n engines by profile or cluster_dir."""
         self.cluster_dir = unicode(cluster_dir)
         dlist = []
         for i in range(n):
-            el = self.launcher_class(work_dir=self.work_dir, config=self.config)
+            el = self.launcher_class(work_dir=self.work_dir, config=self.config, logname=self.log.name)
             # Copy the engine args over to each engine launcher.
             import copy
             el.engine_args = copy.deepcopy(self.engine_args)
             el.on_stop(self._notice_engine_stopped)
             d = el.start(cluster_dir)
             if i==0:
-                logging.info("Starting LocalEngineSetLauncher: %r" % el.args)
+                self.log.info("Starting LocalEngineSetLauncher: %r" % el.args)
             self.launchers[i] = el
             dlist.append(d)
         self.notify_start(dlist)
         # The consumeErrors here could be dangerous
         # dfinal = gatherBoth(dlist, consumeErrors=True)
         # dfinal.addCallback(self.notify_start)
         return dlist
 
     def find_args(self):
         return ['engine set']
 
     def signal(self, sig):
         dlist = []
         for el in self.launchers.itervalues():
             d = el.signal(sig)
             dlist.append(d)
         # dfinal = gatherBoth(dlist, consumeErrors=True)
         return dlist
 
     def interrupt_then_kill(self, delay=1.0):
         dlist = []
         for el in self.launchers.itervalues():
             d = el.interrupt_then_kill(delay)
             dlist.append(d)
         # dfinal = gatherBoth(dlist, consumeErrors=True)
         return dlist
 
     def stop(self):
         return self.interrupt_then_kill()
     
     def _notice_engine_stopped(self, data):
         print "notice", data
         pid = data['pid']
         for idx,el in self.launchers.iteritems():
             if el.process.pid == pid:
                 break
         self.launchers.pop(idx)
         self.stop_data[idx] = data
         if not self.launchers:
             self.notify_stop(self.stop_data)
 
 
 #-----------------------------------------------------------------------------
 # MPIExec launchers
 #-----------------------------------------------------------------------------
 
 
 class MPIExecLauncher(LocalProcessLauncher):
     """Launch an external process using mpiexec."""
 
     # The mpiexec command to use in starting the process.
     mpi_cmd = List(['mpiexec'], config=True)
     # The command line arguments to pass to mpiexec.
     mpi_args = List([], config=True)
     # The program to start using mpiexec.
     program = List(['date'], config=True)
     # The command line argument to the program.
     program_args = List([], config=True)
     # The number of instances of the program to start.
     n = Int(1, config=True)
 
     def find_args(self):
         """Build self.args using all the fields."""
         return self.mpi_cmd + ['-n', self.n] + self.mpi_args + \
                self.program + self.program_args
 
     def start(self, n):
         """Start n instances of the program using mpiexec."""
         self.n = n
         return super(MPIExecLauncher, self).start()
 
 
 class MPIExecControllerLauncher(MPIExecLauncher):
     """Launch a controller using mpiexec."""
 
     controller_cmd = List(ipcontroller_cmd_argv, config=True)
     # Command line arguments to ipcontroller.
     controller_args = List(['--log-to-file','--log-level', str(logging.ERROR)], config=True)
     n = Int(1, config=False)
 
     def start(self, cluster_dir):
         """Start the controller by cluster_dir."""
         self.controller_args.extend(['--cluster-dir', cluster_dir])
         self.cluster_dir = unicode(cluster_dir)
-        logging.info("Starting MPIExecControllerLauncher: %r" % self.args)
+        self.log.info("Starting MPIExecControllerLauncher: %r" % self.args)
         return super(MPIExecControllerLauncher, self).start(1)
 
     def find_args(self):
         return self.mpi_cmd + ['-n', self.n] + self.mpi_args + \
                self.controller_cmd + self.controller_args
 
 
 class MPIExecEngineSetLauncher(MPIExecLauncher):
 
     engine_cmd = List(ipengine_cmd_argv, config=True)
     # Command line arguments for ipengine.
     engine_args = List(
         ['--log-to-file','--log-level', str(logging.ERROR)], config=True
     )
     n = Int(1, config=True)
 
     def start(self, n, cluster_dir):
         """Start n engines by profile or cluster_dir."""
         self.engine_args.extend(['--cluster-dir', cluster_dir])
         self.cluster_dir = unicode(cluster_dir)
         self.n = n
-        logging.info('Starting MPIExecEngineSetLauncher: %r' % self.args)
+        self.log.info('Starting MPIExecEngineSetLauncher: %r' % self.args)
         return super(MPIExecEngineSetLauncher, self).start(n)
 
     def find_args(self):
         return self.mpi_cmd + ['-n', self.n] + self.mpi_args + \
                self.engine_cmd + self.engine_args
 
 
 #-----------------------------------------------------------------------------
 # SSH launchers
 #-----------------------------------------------------------------------------
 
 # TODO: Get SSH Launcher working again.
 
 class SSHLauncher(LocalProcessLauncher):
     """A minimal launcher for ssh.
 
     To be useful this will probably have to be extended to use the ``sshx``
     idea for environment variables.  There could be other things this needs
     as well.
     """
 
     ssh_cmd = List(['ssh'], config=True)
     ssh_args = List([], config=True)
     program = List(['date'], config=True)
     program_args = List([], config=True)
     hostname = Str('', config=True)
     user = Str(os.environ.get('USER','username'), config=True)
     location = Str('')
 
     def _hostname_changed(self, name, old, new):
         self.location = '%s@%s' % (self.user, new)
 
     def _user_changed(self, name, old, new):
         self.location = '%s@%s' % (new, self.hostname)
 
     def find_args(self):
         return self.ssh_cmd + self.ssh_args + [self.location] + \
                self.program + self.program_args
 
     def start(self, cluster_dir, hostname=None, user=None):
         if hostname is not None:
             self.hostname = hostname
         if user is not None:
             self.user = user
         return super(SSHLauncher, self).start()
 
 
 class SSHControllerLauncher(SSHLauncher):
 
     program = List(ipcontroller_cmd_argv, config=True)
     # Command line arguments to ipcontroller.
     program_args = List(['--log-to-file','--log-level', str(logging.ERROR)], config=True)
 
 
 class SSHEngineLauncher(SSHLauncher):
     program = List(ipengine_cmd_argv, config=True)
     # Command line arguments for ipengine.
     program_args = List(
         ['--log-to-file','--log-level', str(logging.ERROR)], config=True
     )
     
 class SSHEngineSetLauncher(LocalEngineSetLauncher):
     launcher_class = SSHEngineLauncher
 
 
 #-----------------------------------------------------------------------------
 # Windows HPC Server 2008 scheduler launchers
 #-----------------------------------------------------------------------------
 
 
 # # This is only used on Windows.
 # def find_job_cmd():
 #     if os.name=='nt':
 #         try:
 #             return find_cmd('job')
 #         except FindCmdError:
 #             return 'job'
 #     else:
 #         return 'job'
 # 
 # 
 # class WindowsHPCLauncher(BaseLauncher):
 # 
 #     # A regular expression used to get the job id from the output of the 
 #     # submit_command.
 #     job_id_regexp = Str(r'\d+', config=True)
 #     # The filename of the instantiated job script.
 #     job_file_name = Unicode(u'ipython_job.xml', config=True)
 #     # The full path to the instantiated job script. This gets made dynamically
 #     # by combining the work_dir with the job_file_name.
 #     job_file = Unicode(u'')
 #     # The hostname of the scheduler to submit the job to
 #     scheduler = Str('', config=True)
 #     job_cmd = Str(find_job_cmd(), config=True)
 # 
 #     def __init__(self, work_dir=u'.', config=None):
 #         super(WindowsHPCLauncher, self).__init__(
 #             work_dir=work_dir, config=config
 #         )
 # 
 #     @property
 #     def job_file(self):
 #         return os.path.join(self.work_dir, self.job_file_name)
 # 
 #     def write_job_file(self, n):
 #         raise NotImplementedError("Implement write_job_file in a subclass.")
 # 
 #     def find_args(self):
 #         return ['job.exe']
 #         
 #     def parse_job_id(self, output):
 #         """Take the output of the submit command and return the job id."""
 #         m = re.search(self.job_id_regexp, output)
 #         if m is not None:
 #             job_id = m.group()
 #         else:
 #             raise LauncherError("Job id couldn't be determined: %s" % output)
 #         self.job_id = job_id
-#         logging.info('Job started with job id: %r' % job_id)
+#         self.log.info('Job started with job id: %r' % job_id)
 #         return job_id
 # 
 #     @inlineCallbacks
 #     def start(self, n):
 #         """Start n copies of the process using the Win HPC job scheduler."""
 #         self.write_job_file(n)
 #         args = [
 #             'submit',
 #             '/jobfile:%s' % self.job_file,
 #             '/scheduler:%s' % self.scheduler
 #         ]
-#         logging.info("Starting Win HPC Job: %s" % (self.job_cmd + ' ' + ' '.join(args),))
+#         self.log.info("Starting Win HPC Job: %s" % (self.job_cmd + ' ' + ' '.join(args),))
 #         # Twisted will raise DeprecationWarnings if we try to pass unicode to this
 #         output = yield getProcessOutput(str(self.job_cmd),
 #             [str(a) for a in args],
 #             env=dict((str(k),str(v)) for k,v in os.environ.items()),
 #             path=self.work_dir
 #         )
 #         job_id = self.parse_job_id(output)
 #         self.notify_start(job_id)
 #         defer.returnValue(job_id)
 # 
 #     @inlineCallbacks
 #     def stop(self):
 #         args = [
 #             'cancel',
 #             self.job_id,
 #             '/scheduler:%s' % self.scheduler
 #         ]
-#         logging.info("Stopping Win HPC Job: %s" % (self.job_cmd + ' ' + ' '.join(args),))
+#         self.log.info("Stopping Win HPC Job: %s" % (self.job_cmd + ' ' + ' '.join(args),))
 #         try:
 #             # Twisted will raise DeprecationWarnings if we try to pass unicode to this
 #             output = yield getProcessOutput(str(self.job_cmd),
 #                 [str(a) for a in args],
 #                 env=dict((str(k),str(v)) for k,v in os.environ.iteritems()),
 #                 path=self.work_dir
 #             )
 #         except:
 #             output = 'The job already appears to be stoppped: %r' % self.job_id
 #         self.notify_stop(output)  # Pass the output of the kill cmd
 #         defer.returnValue(output)
 # 
 # 
 # class WindowsHPCControllerLauncher(WindowsHPCLauncher):
 # 
 #     job_file_name = Unicode(u'ipcontroller_job.xml', config=True)
 #     extra_args = List([], config=False)
 # 
 #     def write_job_file(self, n):
 #         job = IPControllerJob(config=self.config)
 # 
 #         t = IPControllerTask(config=self.config)
 #         # The tasks work directory is *not* the actual work directory of 
 #         # the controller. It is used as the base path for the stdout/stderr
 #         # files that the scheduler redirects to.
 #         t.work_directory = self.cluster_dir
 #         # Add the --cluster-dir and from self.start().
 #         t.controller_args.extend(self.extra_args)
 #         job.add_task(t)
 # 
-#         logging.info("Writing job description file: %s" % self.job_file)
+#         self.log.info("Writing job description file: %s" % self.job_file)
 #         job.write(self.job_file)
 # 
 #     @property
 #     def job_file(self):
 #         return os.path.join(self.cluster_dir, self.job_file_name)
 # 
 #     def start(self, cluster_dir):
 #         """Start the controller by cluster_dir."""
 #         self.extra_args = ['--cluster-dir', cluster_dir]
 #         self.cluster_dir = unicode(cluster_dir)
 #         return super(WindowsHPCControllerLauncher, self).start(1)
 # 
 # 
 # class WindowsHPCEngineSetLauncher(WindowsHPCLauncher):
 # 
 #     job_file_name = Unicode(u'ipengineset_job.xml', config=True)
 #     extra_args = List([], config=False)
 # 
 #     def write_job_file(self, n):
 #         job = IPEngineSetJob(config=self.config)
 # 
 #         for i in range(n):
 #             t = IPEngineTask(config=self.config)
 #             # The tasks work directory is *not* the actual work directory of 
 #             # the engine. It is used as the base path for the stdout/stderr
 #             # files that the scheduler redirects to.
 #             t.work_directory = self.cluster_dir
 #             # Add the --cluster-dir and from self.start().
 #             t.engine_args.extend(self.extra_args)
 #             job.add_task(t)
 # 
-#         logging.info("Writing job description file: %s" % self.job_file)
+#         self.log.info("Writing job description file: %s" % self.job_file)
 #         job.write(self.job_file)
 # 
 #     @property
 #     def job_file(self):
 #         return os.path.join(self.cluster_dir, self.job_file_name)
 # 
 #     def start(self, n, cluster_dir):
 #         """Start the controller by cluster_dir."""
 #         self.extra_args = ['--cluster-dir', cluster_dir]
 #         self.cluster_dir = unicode(cluster_dir)
 #         return super(WindowsHPCEngineSetLauncher, self).start(n)
 # 
 # 
 # #-----------------------------------------------------------------------------
 # # Batch (PBS) system launchers
 # #-----------------------------------------------------------------------------
 # 
 # # TODO: Get PBS launcher working again.
 # 
 # class BatchSystemLauncher(BaseLauncher):
 #     """Launch an external process using a batch system.
 # 
 #     This class is designed to work with UNIX batch systems like PBS, LSF,
 #     GridEngine, etc.  The overall model is that there are different commands
 #     like qsub, qdel, etc. that handle the starting and stopping of the process.
 # 
 #     This class also has the notion of a batch script. The ``batch_template``
 #     attribute can be set to a string that is a template for the batch script.
 #     This template is instantiated using Itpl. Thus the template can use
 #     ${n} fot the number of instances. Subclasses can add additional variables
 #     to the template dict.
 #     """
 # 
 #     # Subclasses must fill these in.  See PBSEngineSet
 #     # The name of the command line program used to submit jobs.
 #     submit_command = Str('', config=True)
 #     # The name of the command line program used to delete jobs.
 #     delete_command = Str('', config=True)
 #     # A regular expression used to get the job id from the output of the 
 #     # submit_command.
 #     job_id_regexp = Str('', config=True)
 #     # The string that is the batch script template itself.
 #     batch_template = Str('', config=True)
 #     # The filename of the instantiated batch script.
 #     batch_file_name = Unicode(u'batch_script', config=True)
 #     # The full path to the instantiated batch script.
 #     batch_file = Unicode(u'')
 # 
 #     def __init__(self, work_dir=u'.', config=None):
 #         super(BatchSystemLauncher, self).__init__(
 #             work_dir=work_dir, config=config
 #         )
 #         self.batch_file = os.path.join(self.work_dir, self.batch_file_name)
 #         self.context = {}
 # 
 #     def parse_job_id(self, output):
 #         """Take the output of the submit command and return the job id."""
 #         m = re.match(self.job_id_regexp, output)
 #         if m is not None:
 #             job_id = m.group()
 #         else:
 #             raise LauncherError("Job id couldn't be determined: %s" % output)
 #         self.job_id = job_id
-#         logging.info('Job started with job id: %r' % job_id)
+#         self.log.info('Job started with job id: %r' % job_id)
 #         return job_id
 # 
 #     def write_batch_script(self, n):
 #         """Instantiate and write the batch script to the work_dir."""
 #         self.context['n'] = n
 #         script_as_string = Itpl.itplns(self.batch_template, self.context)
-#         logging.info('Writing instantiated batch script: %s' % self.batch_file)
+#         self.log.info('Writing instantiated batch script: %s' % self.batch_file)
 #         f = open(self.batch_file, 'w')
 #         f.write(script_as_string)
 #         f.close()
 # 
 #     @inlineCallbacks
 #     def start(self, n):
 #         """Start n copies of the process using a batch system."""
 #         self.write_batch_script(n)
 #         output = yield getProcessOutput(self.submit_command,
 #             [self.batch_file], env=os.environ)
 #         job_id = self.parse_job_id(output)
 #         self.notify_start(job_id)
 #         defer.returnValue(job_id)
 # 
 #     @inlineCallbacks
 #     def stop(self):
 #         output = yield getProcessOutput(self.delete_command,
 #             [self.job_id], env=os.environ
 #         )
 #         self.notify_stop(output)  # Pass the output of the kill cmd
 #         defer.returnValue(output)
 # 
 # 
 # class PBSLauncher(BatchSystemLauncher):
 #     """A BatchSystemLauncher subclass for PBS."""
 # 
 #     submit_command = Str('qsub', config=True)
 #     delete_command = Str('qdel', config=True)
 #     job_id_regexp = Str(r'\d+', config=True)
 #     batch_template = Str('', config=True)
 #     batch_file_name = Unicode(u'pbs_batch_script', config=True)
 #     batch_file = Unicode(u'')
 # 
 # 
 # class PBSControllerLauncher(PBSLauncher):
 #     """Launch a controller using PBS."""
 # 
 #     batch_file_name = Unicode(u'pbs_batch_script_controller', config=True)
 # 
 #     def start(self, cluster_dir):
 #         """Start the controller by profile or cluster_dir."""
 #         # Here we save profile and cluster_dir in the context so they
 #         # can be used in the batch script template as ${profile} and
 #         # ${cluster_dir}
 #         self.context['cluster_dir'] = cluster_dir
 #         self.cluster_dir = unicode(cluster_dir)
-#         logging.info("Starting PBSControllerLauncher: %r" % self.args)
+#         self.log.info("Starting PBSControllerLauncher: %r" % self.args)
 #         return super(PBSControllerLauncher, self).start(1)
 # 
 # 
 # class PBSEngineSetLauncher(PBSLauncher):
 # 
 #     batch_file_name = Unicode(u'pbs_batch_script_engines', config=True)
 # 
 #     def start(self, n, cluster_dir):
 #         """Start n engines by profile or cluster_dir."""
 #         self.program_args.extend(['--cluster-dir', cluster_dir])
 #         self.cluster_dir = unicode(cluster_dir)
-#         logging.info('Starting PBSEngineSetLauncher: %r' % self.args)
+#         self.log.info('Starting PBSEngineSetLauncher: %r' % self.args)
 #         return super(PBSEngineSetLauncher, self).start(n)
 
 
 #-----------------------------------------------------------------------------
 # A launcher for ipcluster itself!
 #-----------------------------------------------------------------------------
 
 
 class IPClusterLauncher(LocalProcessLauncher):
     """Launch the ipcluster program in an external process."""
 
     ipcluster_cmd = List(ipcluster_cmd_argv, config=True)
     # Command line arguments to pass to ipcluster.
     ipcluster_args = List(
         ['--clean-logs', '--log-to-file', '--log-level', str(logging.ERROR)], config=True)
     ipcluster_subcommand = Str('start')
     ipcluster_n = Int(2)
 
     def find_args(self):
         return self.ipcluster_cmd + [self.ipcluster_subcommand] + \
             ['-n', repr(self.ipcluster_n)] + self.ipcluster_args
 
     def start(self):
-        logging.info("Starting ipcluster: %r" % self.args)
+        self.log.info("Starting ipcluster: %r" % self.args)
         return super(IPClusterLauncher, self).start()
 

IPython/zmq/parallel/logwatcher.py

@@ -1,92 +1,97 b''
 #!/usr/bin/env python
 """A simple logger object that consolidates messages incoming from ipclusterz processes."""
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2011  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 
 import sys
 import logging
 
 import zmq
 from zmq.eventloop import ioloop, zmqstream
-from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import Int, Str, Instance, List
 
+from factory import LoggingFactory
+
 #-----------------------------------------------------------------------------
 # Classes
 #-----------------------------------------------------------------------------
 
 
-class LogWatcher(Configurable):
+class LogWatcher(LoggingFactory):
     """A simple class that receives messages on a SUB socket, as published
     by subclasses of `zmq.log.handlers.PUBHandler`, and logs them itself.
     
     This can subscribe to multiple topics, but defaults to all topics.
     """
     # configurables
     topics = List([''], config=True)
     url = Str('tcp://127.0.0.1:20202', config=True)
     
     # internals
     context = Instance(zmq.Context, (), {})
     stream = Instance('zmq.eventloop.zmqstream.ZMQStream')
     loop = Instance('zmq.eventloop.ioloop.IOLoop')
     def _loop_default(self):
         return ioloop.IOLoop.instance()
     
-    def __init__(self, config=None):
-        super(LogWatcher, self).__init__(config=config)
+    def __init__(self, **kwargs):
+        super(LogWatcher, self).__init__(**kwargs)
         s = self.context.socket(zmq.SUB)
         s.bind(self.url)
         self.stream = zmqstream.ZMQStream(s, self.loop)
         self.subscribe()
         self.on_trait_change(self.subscribe, 'topics')
-        
+    
+    def start(self):
         self.stream.on_recv(self.log_message)
     
+    def stop(self):
+        self.stream.stop_on_recv()
+    
     def subscribe(self):
         """Update our SUB socket's subscriptions."""
         self.stream.setsockopt(zmq.UNSUBSCRIBE, '')
         for topic in self.topics:
-            logging.debug("Subscribing to: %r"%topic)
+            self.log.debug("Subscribing to: %r"%topic)
             self.stream.setsockopt(zmq.SUBSCRIBE, topic)
     
     def _extract_level(self, topic_str):
         """Turn 'engine.0.INFO.extra' into (logging.INFO, 'engine.0.extra')"""
         topics = topic_str.split('.')
         for idx,t in enumerate(topics):
             level = getattr(logging, t, None)
             if level is not None:
                 break
         
         if level is None:
             level = logging.INFO
         else:
             topics.pop(idx)
         
         return level, '.'.join(topics)
             
             
     def log_message(self, raw):
         """receive and parse a message, then log it."""
         if len(raw) != 2 or '.' not in raw[0]:
-            logging.error("Invalid log message: %s"%raw)
+            self.log.error("Invalid log message: %s"%raw)
             return
         else:
             topic, msg = raw
             # don't newline, since log messages always newline:
             topic,level_name = topic.rsplit('.',1)
             level,topic = self._extract_level(topic)
             if msg[-1] == '\n':
                 msg = msg[:-1]
             logging.log(level, "[%s] %s" % (topic, msg))
 

IPython/zmq/parallel/scheduler.py

@@ -1,509 +1,511 b''
 """The Python scheduler for rich scheduling.
 
 The Pure ZMQ scheduler does not allow routing schemes other than LRU,
 nor does it check msg_id DAG dependencies. For those, a slightly slower
 Python Scheduler exists.
 """
 
 #----------------------------------------------------------------------
 # Imports
 #----------------------------------------------------------------------
 
 from __future__ import print_function
-from random import randint,random
+import sys
 import logging
+from random import randint,random
 from types import FunctionType
 
 try:
     import numpy
 except ImportError:
     numpy = None
 
 import zmq
 from zmq.eventloop import ioloop, zmqstream
 
 # local imports
 from IPython.external.decorator import decorator
-from IPython.config.configurable import Configurable
+# from IPython.config.configurable import Configurable
 from IPython.utils.traitlets import Instance, Dict, List, Set
 
 import error
 from client import Client
 from dependency import Dependency
 import streamsession as ss
 from entry_point import connect_logger, local_logger
+from factory import LoggingFactory
 
 
 @decorator
 def logged(f,self,*args,**kwargs):
     # print ("#--------------------")
-    logging.debug("scheduler::%s(*%s,**%s)"%(f.func_name, args, kwargs))
+    self.log.debug("scheduler::%s(*%s,**%s)"%(f.func_name, args, kwargs))
     # print ("#--")
     return f(self,*args, **kwargs)
 
 #----------------------------------------------------------------------
 # Chooser functions
 #----------------------------------------------------------------------
 
 def plainrandom(loads):
     """Plain random pick."""
     n = len(loads)
     return randint(0,n-1)
 
 def lru(loads):
     """Always pick the front of the line.
     
     The content of `loads` is ignored.
     
     Assumes LRU ordering of loads, with oldest first.
     """
     return 0
 
 def twobin(loads):
     """Pick two at random, use the LRU of the two.
     
     The content of loads is ignored.
     
     Assumes LRU ordering of loads, with oldest first.
     """
     n = len(loads)
     a = randint(0,n-1)
     b = randint(0,n-1)
     return min(a,b)
 
 def weighted(loads):
     """Pick two at random using inverse load as weight.
     
     Return the less loaded of the two.
     """
     # weight 0 a million times more than 1:
     weights = 1./(1e-6+numpy.array(loads))
     sums = weights.cumsum()
     t = sums[-1]
     x = random()*t
     y = random()*t
     idx = 0
     idy = 0
     while sums[idx] < x:
         idx += 1
     while sums[idy] < y:
         idy += 1
     if weights[idy] > weights[idx]:
         return idy
     else:
         return idx
 
 def leastload(loads):
     """Always choose the lowest load.
     
     If the lowest load occurs more than once, the first
     occurance will be used.  If loads has LRU ordering, this means
     the LRU of those with the lowest load is chosen.
     """
     return loads.index(min(loads))
 
 #---------------------------------------------------------------------
 # Classes
 #---------------------------------------------------------------------
 # store empty default dependency:
 MET = Dependency([])
 
-class TaskScheduler(Configurable):
+class TaskScheduler(LoggingFactory):
     """Python TaskScheduler object.
     
     This is the simplest object that supports msg_id based
     DAG dependencies. *Only* task msg_ids are checked, not
     msg_ids of jobs submitted via the MUX queue.
     
     """
     
     # input arguments:
     scheme = Instance(FunctionType, default=leastload) # function for determining the destination
     client_stream = Instance(zmqstream.ZMQStream) # client-facing stream
     engine_stream = Instance(zmqstream.ZMQStream) # engine-facing stream
     notifier_stream = Instance(zmqstream.ZMQStream) # hub-facing sub stream
     mon_stream = Instance(zmqstream.ZMQStream) # hub-facing pub stream
     io_loop = Instance(ioloop.IOLoop)
     
     # internals:
     dependencies = Dict() # dict by msg_id of [ msg_ids that depend on key ]
     depending = Dict() # dict by msg_id of (msg_id, raw_msg, after, follow)
     pending = Dict() # dict by engine_uuid of submitted tasks
     completed = Dict() # dict by engine_uuid of completed tasks
     failed = Dict() # dict by engine_uuid of failed tasks
     destinations = Dict() # dict by msg_id of engine_uuids where jobs ran (reverse of completed+failed)
     clients = Dict() # dict by msg_id for who submitted the task
     targets = List() # list of target IDENTs
     loads = List() # list of engine loads
     all_completed = Set() # set of all completed tasks
     all_failed = Set() # set of all failed tasks
     all_done = Set() # set of all finished tasks=union(completed,failed)
     blacklist = Dict() # dict by msg_id of locations where a job has encountered UnmetDependency
     session = Instance(ss.StreamSession)
     
     
     def __init__(self, **kwargs):
         super(TaskScheduler, self).__init__(**kwargs)
         
         self.session = ss.StreamSession(username="TaskScheduler")
         
         self.engine_stream.on_recv(self.dispatch_result, copy=False)
         self._notification_handlers = dict(
             registration_notification = self._register_engine,
             unregistration_notification = self._unregister_engine
         )
         self.notifier_stream.on_recv(self.dispatch_notification)
-        logging.info("Scheduler started...%r"%self)
+        self.log.info("Scheduler started...%r"%self)
     
     def resume_receiving(self):
         """Resume accepting jobs."""
         self.client_stream.on_recv(self.dispatch_submission, copy=False)
     
     def stop_receiving(self):
         """Stop accepting jobs while there are no engines.
         Leave them in the ZMQ queue."""
         self.client_stream.on_recv(None)
     
     #-----------------------------------------------------------------------
     # [Un]Registration Handling
     #-----------------------------------------------------------------------
     
     def dispatch_notification(self, msg):
         """dispatch register/unregister events."""
         idents,msg = self.session.feed_identities(msg)
         msg = self.session.unpack_message(msg)
         msg_type = msg['msg_type']
         handler = self._notification_handlers.get(msg_type, None)
         if handler is None:
             raise Exception("Unhandled message type: %s"%msg_type)
         else:
             try:
                 handler(str(msg['content']['queue']))
             except KeyError:
-                logging.error("task::Invalid notification msg: %s"%msg)
+                self.log.error("task::Invalid notification msg: %s"%msg)
     
     @logged
     def _register_engine(self, uid):
         """New engine with ident `uid` became available."""
         # head of the line:
         self.targets.insert(0,uid)
         self.loads.insert(0,0)
         # initialize sets
         self.completed[uid] = set()
         self.failed[uid] = set()
         self.pending[uid] = {}
         if len(self.targets) == 1:
             self.resume_receiving()
 
     def _unregister_engine(self, uid):
         """Existing engine with ident `uid` became unavailable."""
         if len(self.targets) == 1:
             # this was our only engine
             self.stop_receiving()
         
         # handle any potentially finished tasks:
         self.engine_stream.flush()
         
         self.completed.pop(uid)
         self.failed.pop(uid)
         # don't pop destinations, because it might be used later
         # map(self.destinations.pop, self.completed.pop(uid))
         # map(self.destinations.pop, self.failed.pop(uid))
         
         lost = self.pending.pop(uid)
         
         idx = self.targets.index(uid)
         self.targets.pop(idx)
         self.loads.pop(idx)
         
         self.handle_stranded_tasks(lost)
     
     def handle_stranded_tasks(self, lost):
         """Deal with jobs resident in an engine that died."""
         # TODO: resubmit the tasks?
         for msg_id in lost:
             pass
     
     
     #-----------------------------------------------------------------------
     # Job Submission
     #-----------------------------------------------------------------------
     @logged
     def dispatch_submission(self, raw_msg):
         """Dispatch job submission to appropriate handlers."""
         # ensure targets up to date:
         self.notifier_stream.flush()
         try:
             idents, msg = self.session.feed_identities(raw_msg, copy=False)
         except Exception as e:
-            logging.error("task::Invaid msg: %s"%msg)
+            self.log.error("task::Invaid msg: %s"%msg)
             return
         
         # send to monitor
         self.mon_stream.send_multipart(['intask']+raw_msg, copy=False)
         
         msg = self.session.unpack_message(msg, content=False, copy=False)
         header = msg['header']
         msg_id = header['msg_id']
         
         # time dependencies
         after = Dependency(header.get('after', []))
         if after.mode == 'all':
             after.difference_update(self.all_completed)
             if not after.success_only:
                 after.difference_update(self.all_failed)
         if after.check(self.all_completed, self.all_failed):
             # recast as empty set, if `after` already met,
             # to prevent unnecessary set comparisons
             after = MET
         
         # location dependencies
         follow = Dependency(header.get('follow', []))
         
         # check if unreachable:
         if after.unreachable(self.all_failed) or follow.unreachable(self.all_failed):
             self.depending[msg_id] = [raw_msg,MET,MET]
             return self.fail_unreachable(msg_id)
         
         if after.check(self.all_completed, self.all_failed):
             # time deps already met, try to run
             if not self.maybe_run(msg_id, raw_msg, follow):
                 # can't run yet
                 self.save_unmet(msg_id, raw_msg, after, follow)
         else:
             self.save_unmet(msg_id, raw_msg, after, follow)
     
     @logged
     def fail_unreachable(self, msg_id):
         """a message has become unreachable"""
         if msg_id not in self.depending:
-            logging.error("msg %r already failed!"%msg_id)
+            self.log.error("msg %r already failed!"%msg_id)
             return
         raw_msg, after, follow = self.depending.pop(msg_id)
         for mid in follow.union(after):
             if mid in self.dependencies:
                 self.dependencies[mid].remove(msg_id)
         
         idents,msg = self.session.feed_identities(raw_msg, copy=False)
         msg = self.session.unpack_message(msg, copy=False, content=False)
         header = msg['header']
         
         try:
             raise error.ImpossibleDependency()
         except:
             content = ss.wrap_exception()
         
         self.all_done.add(msg_id)
         self.all_failed.add(msg_id)
         
         msg = self.session.send(self.client_stream, 'apply_reply', content, 
                                                 parent=header, ident=idents)
         self.session.send(self.mon_stream, msg, ident=['outtask']+idents)
         
         self.update_dependencies(msg_id, success=False)
     
     @logged
     def maybe_run(self, msg_id, raw_msg, follow=None):
         """check location dependencies, and run if they are met."""
             
         if follow:
             def can_run(idx):
                 target = self.targets[idx]
                 return target not in self.blacklist.get(msg_id, []) and\
                         follow.check(self.completed[target], self.failed[target])
             
             indices = filter(can_run, range(len(self.targets)))
             if not indices:
                 # TODO evaluate unmeetable follow dependencies
                 if follow.mode == 'all':
                     dests = set()
                     relevant = self.all_completed if follow.success_only else self.all_done
                     for m in follow.intersection(relevant):
                         dests.add(self.destinations[m])
                     if len(dests) > 1:
                         self.fail_unreachable(msg_id)
                 
                 
                 return False
         else:
             indices = None
             
         self.submit_task(msg_id, raw_msg, indices)
         return True
             
     @logged
     def save_unmet(self, msg_id, raw_msg, after, follow):
         """Save a message for later submission when its dependencies are met."""
         self.depending[msg_id] = [raw_msg,after,follow]
         # track the ids in follow or after, but not those already finished
         for dep_id in after.union(follow).difference(self.all_done):
             if dep_id not in self.dependencies:
                 self.dependencies[dep_id] = set()
             self.dependencies[dep_id].add(msg_id)
     
     @logged
     def submit_task(self, msg_id, msg, follow=None, indices=None):
         """Submit a task to any of a subset of our targets."""
         if indices:
             loads = [self.loads[i] for i in indices]
         else:
             loads = self.loads
         idx = self.scheme(loads)
         if indices:
             idx = indices[idx]
         target = self.targets[idx]
         # print (target, map(str, msg[:3]))
         self.engine_stream.send(target, flags=zmq.SNDMORE, copy=False)
         self.engine_stream.send_multipart(msg, copy=False)
         self.add_job(idx)
         self.pending[target][msg_id] = (msg, follow)
         content = dict(msg_id=msg_id, engine_id=target)
         self.session.send(self.mon_stream, 'task_destination', content=content, 
                         ident=['tracktask',self.session.session])
     
     #-----------------------------------------------------------------------
     # Result Handling
     #-----------------------------------------------------------------------
     @logged
     def dispatch_result(self, raw_msg):
         try:
             idents,msg = self.session.feed_identities(raw_msg, copy=False)
         except Exception as e:
-            logging.error("task::Invaid result: %s"%msg)
+            self.log.error("task::Invaid result: %s"%msg)
             return
         msg = self.session.unpack_message(msg, content=False, copy=False)
         header = msg['header']
         if header.get('dependencies_met', True):
             success = (header['status'] == 'ok')
             self.handle_result(idents, msg['parent_header'], raw_msg, success)
             # send to Hub monitor
             self.mon_stream.send_multipart(['outtask']+raw_msg, copy=False)
         else:
             self.handle_unmet_dependency(idents, msg['parent_header'])
         
     @logged
     def handle_result(self, idents, parent, raw_msg, success=True):
         # first, relay result to client
         engine = idents[0]
         client = idents[1]
         # swap_ids for XREP-XREP mirror
         raw_msg[:2] = [client,engine]
         # print (map(str, raw_msg[:4]))
         self.client_stream.send_multipart(raw_msg, copy=False)
         # now, update our data structures
         msg_id = parent['msg_id']
         self.pending[engine].pop(msg_id)
         if success:
             self.completed[engine].add(msg_id)
             self.all_completed.add(msg_id)
         else:
             self.failed[engine].add(msg_id)
             self.all_failed.add(msg_id)
         self.all_done.add(msg_id)
         self.destinations[msg_id] = engine
         
         self.update_dependencies(msg_id, success)
         
     @logged
     def handle_unmet_dependency(self, idents, parent):
         engine = idents[0]
         msg_id = parent['msg_id']
         if msg_id not in self.blacklist:
             self.blacklist[msg_id] = set()
         self.blacklist[msg_id].add(engine)
         raw_msg,follow = self.pending[engine].pop(msg_id)
         if not self.maybe_run(msg_id, raw_msg, follow):
             # resubmit failed, put it back in our dependency tree
             self.save_unmet(msg_id, raw_msg, MET, follow)
         pass
     
     @logged
     def update_dependencies(self, dep_id, success=True):
         """dep_id just finished. Update our dependency
         table and submit any jobs that just became runable."""
         # print ("\n\n***********")
         # pprint (dep_id)
         # pprint (self.dependencies)
         # pprint (self.depending)
         # pprint (self.all_completed)
         # pprint (self.all_failed)
         # print ("\n\n***********\n\n")
         if dep_id not in self.dependencies:
             return
         jobs = self.dependencies.pop(dep_id)
         
         for msg_id in jobs:
             raw_msg, after, follow = self.depending[msg_id]
             # if dep_id in after:
             #     if after.mode == 'all' and (success or not after.success_only):
             #         after.remove(dep_id)
             
             if after.unreachable(self.all_failed) or follow.unreachable(self.all_failed):
                 self.fail_unreachable(msg_id)
             
             elif after.check(self.all_completed, self.all_failed): # time deps met, maybe run
                 self.depending[msg_id][1] = MET
                 if self.maybe_run(msg_id, raw_msg, follow):
                     
                     self.depending.pop(msg_id)
                     for mid in follow.union(after):
                         if mid in self.dependencies:
                             self.dependencies[mid].remove(msg_id)
     
     #----------------------------------------------------------------------
     # methods to be overridden by subclasses
     #----------------------------------------------------------------------
     
     def add_job(self, idx):
         """Called after self.targets[idx] just got the job with header.
         Override with subclasses.  The default ordering is simple LRU.
         The default loads are the number of outstanding jobs."""
         self.loads[idx] += 1
         for lis in (self.targets, self.loads):
             lis.append(lis.pop(idx))
             
     
     def finish_job(self, idx):
         """Called after self.targets[idx] just finished a job.
         Override with subclasses."""
         self.loads[idx] -= 1
     
 
 
-def launch_scheduler(in_addr, out_addr, mon_addr, not_addr, log_addr=None, loglevel=logging.DEBUG, scheme='weighted'):
+def launch_scheduler(in_addr, out_addr, mon_addr, not_addr, logname='ZMQ', log_addr=None, loglevel=logging.DEBUG, scheme='weighted'):
     from zmq.eventloop import ioloop
     from zmq.eventloop.zmqstream import ZMQStream
     
     ctx = zmq.Context()
     loop = ioloop.IOLoop()
     
     ins = ZMQStream(ctx.socket(zmq.XREP),loop)
     ins.bind(in_addr)
     outs = ZMQStream(ctx.socket(zmq.XREP),loop)
     outs.bind(out_addr)
     mons = ZMQStream(ctx.socket(zmq.PUB),loop)
     mons.connect(mon_addr)
     nots = ZMQStream(ctx.socket(zmq.SUB),loop)
     nots.setsockopt(zmq.SUBSCRIBE, '')
     nots.connect(not_addr)
     
     scheme = globals().get(scheme, None)
     # setup logging
     if log_addr:
-        connect_logger(ctx, log_addr, root="scheduler", loglevel=loglevel)
+        connect_logger(logname, ctx, log_addr, root="scheduler", loglevel=loglevel)
     else:
-        local_logger(loglevel)
+        local_logger(logname, loglevel)
     
     scheduler = TaskScheduler(client_stream=ins, engine_stream=outs,
                             mon_stream=mons,notifier_stream=nots,
-                            scheme=scheme,io_loop=loop)
+                            scheme=scheme,io_loop=loop, logname=logname)
     
     try:
         loop.start()
     except KeyboardInterrupt:
         print ("interrupted, exiting...", file=sys.__stderr__)
 
 
 if __name__ == '__main__':
     iface = 'tcp://127.0.0.1:%i'
     launch_scheduler(iface%12345,iface%1236,iface%12347,iface%12348)

IPython/zmq/parallel/streamkernel.py

@@ -1,483 +1,483 b''
 #!/usr/bin/env python
 """
 Kernel adapted from kernel.py to use ZMQ Streams
 """
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 # Standard library imports.
 from __future__ import print_function
 import __builtin__
 from code import CommandCompiler
 import os
 import sys
 import time
 import traceback
 import logging
 from datetime import datetime
 from signal import SIGTERM, SIGKILL
 from pprint import pprint
 
 # System library imports.
 import zmq
 from zmq.eventloop import ioloop, zmqstream
 
 # Local imports.
 from IPython.core import ultratb
 from IPython.utils.traitlets import HasTraits, Instance, List, Int, Dict, Set, Str
 from IPython.zmq.completer import KernelCompleter
 from IPython.zmq.iostream import OutStream
 from IPython.zmq.displayhook import DisplayHook
 
 from factory import SessionFactory
 from streamsession import StreamSession, Message, extract_header, serialize_object,\
                 unpack_apply_message, ISO8601, wrap_exception
 import heartmonitor
 from client import Client
 
 def printer(*args):
     pprint(args, stream=sys.__stdout__)
 
 
 class _Passer:
     """Empty class that implements `send()` that does nothing."""
     def send(self, *args, **kwargs):
         pass
     send_multipart = send
     
 
 #-----------------------------------------------------------------------------
 # Main kernel class
 #-----------------------------------------------------------------------------
 
 class Kernel(SessionFactory):
 
     #---------------------------------------------------------------------------
     # Kernel interface
     #---------------------------------------------------------------------------
     
     # kwargs:
     int_id = Int(-1, config=True)
     user_ns = Dict(config=True)
     exec_lines = List(config=True)
     
     control_stream = Instance(zmqstream.ZMQStream)
     task_stream = Instance(zmqstream.ZMQStream)
     iopub_stream = Instance(zmqstream.ZMQStream)
     client = Instance('IPython.zmq.parallel.client.Client')
     
     # internals
     shell_streams = List()
     compiler = Instance(CommandCompiler, (), {})
     completer = Instance(KernelCompleter)
     
     aborted = Set()
     shell_handlers = Dict()
     control_handlers = Dict()
     
     def _set_prefix(self):
         self.prefix = "engine.%s"%self.int_id
     
     def _connect_completer(self):
         self.completer = KernelCompleter(self.user_ns)
     
     def __init__(self, **kwargs):
         super(Kernel, self).__init__(**kwargs)
         self._set_prefix()
         self._connect_completer()
         
         self.on_trait_change(self._set_prefix, 'id')
         self.on_trait_change(self._connect_completer, 'user_ns')
         
         # Build dict of handlers for message types
         for msg_type in ['execute_request', 'complete_request', 'apply_request', 
                 'clear_request']:
             self.shell_handlers[msg_type] = getattr(self, msg_type)
         
         for msg_type in ['shutdown_request', 'abort_request']+self.shell_handlers.keys():
             self.control_handlers[msg_type] = getattr(self, msg_type)
         
         self._initial_exec_lines()
     
     def _wrap_exception(self, method=None):
         e_info = dict(engineid=self.ident, method=method)
         content=wrap_exception(e_info)
         return content
     
     def _initial_exec_lines(self):
         s = _Passer()
         content = dict(silent=True, user_variable=[],user_expressions=[])
         for line in self.exec_lines:
-            logging.debug("executing initialization: %s"%line)
+            self.log.debug("executing initialization: %s"%line)
             content.update({'code':line})
             msg = self.session.msg('execute_request', content)
             self.execute_request(s, [], msg)
         
         
     #-------------------- control handlers -----------------------------
     def abort_queues(self):
         for stream in self.shell_streams:
             if stream:
                 self.abort_queue(stream)
     
     def abort_queue(self, stream):
         while True:
             try:
                 msg = self.session.recv(stream, zmq.NOBLOCK,content=True)
             except zmq.ZMQError as e:
                 if e.errno == zmq.EAGAIN:
                     break
                 else:
                     return
             else:
                 if msg is None:
                     return
                 else:
                     idents,msg = msg
                 
                 # assert self.reply_socketly_socket.rcvmore(), "Unexpected missing message part."
                 # msg = self.reply_socket.recv_json()
-            logging.info("Aborting:")
-            logging.info(str(msg))
+            self.log.info("Aborting:")
+            self.log.info(str(msg))
             msg_type = msg['msg_type']
             reply_type = msg_type.split('_')[0] + '_reply'
             # reply_msg = self.session.msg(reply_type, {'status' : 'aborted'}, msg)
             # self.reply_socket.send(ident,zmq.SNDMORE)
             # self.reply_socket.send_json(reply_msg)
             reply_msg = self.session.send(stream, reply_type, 
                         content={'status' : 'aborted'}, parent=msg, ident=idents)[0]
-            logging.debug(str(reply_msg))
+            self.log.debug(str(reply_msg))
             # We need to wait a bit for requests to come in. This can probably
             # be set shorter for true asynchronous clients.
             time.sleep(0.05)
     
     def abort_request(self, stream, ident, parent):
         """abort a specifig msg by id"""
         msg_ids = parent['content'].get('msg_ids', None)
         if isinstance(msg_ids, basestring):
             msg_ids = [msg_ids]
         if not msg_ids:
             self.abort_queues()
         for mid in msg_ids:
             self.aborted.add(str(mid))
         
         content = dict(status='ok')
         reply_msg = self.session.send(stream, 'abort_reply', content=content, 
                 parent=parent, ident=ident)[0]
-        logging.debug(str(reply_msg))
+        self.log.debug(str(reply_msg))
     
     def shutdown_request(self, stream, ident, parent):
         """kill ourself.  This should really be handled in an external process"""
         try:
             self.abort_queues()
         except:
             content = self._wrap_exception('shutdown')
         else:
             content = dict(parent['content'])
             content['status'] = 'ok'
         msg = self.session.send(stream, 'shutdown_reply',
                                 content=content, parent=parent, ident=ident)
         # msg = self.session.send(self.pub_socket, 'shutdown_reply',
         #                         content, parent, ident)
         # print >> sys.__stdout__, msg
         # time.sleep(0.2)
         dc = ioloop.DelayedCallback(lambda : sys.exit(0), 1000, self.loop)
         dc.start()
     
     def dispatch_control(self, msg):
         idents,msg = self.session.feed_identities(msg, copy=False)
         try:
             msg = self.session.unpack_message(msg, content=True, copy=False)
         except:
-            logging.error("Invalid Message", exc_info=True)
+            self.log.error("Invalid Message", exc_info=True)
             return
         
         header = msg['header']
         msg_id = header['msg_id']
         
         handler = self.control_handlers.get(msg['msg_type'], None)
         if handler is None:
-            logging.error("UNKNOWN CONTROL MESSAGE TYPE: %r"%msg['msg_type'])
+            self.log.error("UNKNOWN CONTROL MESSAGE TYPE: %r"%msg['msg_type'])
         else:
             handler(self.control_stream, idents, msg)
     
 
     #-------------------- queue helpers ------------------------------
     
     def check_dependencies(self, dependencies):
         if not dependencies:
             return True
         if len(dependencies) == 2 and dependencies[0] in 'any all'.split():
             anyorall = dependencies[0]
             dependencies = dependencies[1]
         else:
             anyorall = 'all'
         results = self.client.get_results(dependencies,status_only=True)
         if results['status'] != 'ok':
             return False
         
         if anyorall == 'any':
             if not results['completed']:
                 return False
         else:
             if results['pending']:
                 return False
         
         return True
     
     def check_aborted(self, msg_id):
         return msg_id in self.aborted
     
     #-------------------- queue handlers -----------------------------
     
     def clear_request(self, stream, idents, parent):
         """Clear our namespace."""
         self.user_ns = {}
         msg = self.session.send(stream, 'clear_reply', ident=idents, parent=parent, 
                 content = dict(status='ok'))
         self._initial_exec_lines()
     
     def execute_request(self, stream, ident, parent):
-        logging.debug('execute request %s'%parent)
+        self.log.debug('execute request %s'%parent)
         try:
             code = parent[u'content'][u'code']
         except:
-            logging.error("Got bad msg: %s"%parent, exc_info=True)
+            self.log.error("Got bad msg: %s"%parent, exc_info=True)
             return
         self.session.send(self.iopub_stream, u'pyin', {u'code':code},parent=parent,
                             ident='%s.pyin'%self.prefix)
         started = datetime.now().strftime(ISO8601)
         try:
             comp_code = self.compiler(code, '<zmq-kernel>')
             # allow for not overriding displayhook
             if hasattr(sys.displayhook, 'set_parent'):
                 sys.displayhook.set_parent(parent)
                 sys.stdout.set_parent(parent)
                 sys.stderr.set_parent(parent)
             exec comp_code in self.user_ns, self.user_ns
         except:
             exc_content = self._wrap_exception('execute')
             # exc_msg = self.session.msg(u'pyerr', exc_content, parent)
             self.session.send(self.iopub_stream, u'pyerr', exc_content, parent=parent,
                             ident='%s.pyerr'%self.prefix)
             reply_content = exc_content
         else:
             reply_content = {'status' : 'ok'}
         
         reply_msg = self.session.send(stream, u'execute_reply', reply_content, parent=parent, 
                     ident=ident, subheader = dict(started=started))
-        logging.debug(str(reply_msg))
+        self.log.debug(str(reply_msg))
         if reply_msg['content']['status'] == u'error':
             self.abort_queues()
 
     def complete_request(self, stream, ident, parent):
         matches = {'matches' : self.complete(parent),
                    'status' : 'ok'}
         completion_msg = self.session.send(stream, 'complete_reply',
                                            matches, parent, ident)
         # print >> sys.__stdout__, completion_msg
 
     def complete(self, msg):
         return self.completer.complete(msg.content.line, msg.content.text)
     
     def apply_request(self, stream, ident, parent):
         # print (parent)
         try:
             content = parent[u'content']
             bufs = parent[u'buffers']
             msg_id = parent['header']['msg_id']
             bound = content.get('bound', False)
         except:
-            logging.error("Got bad msg: %s"%parent, exc_info=True)
+            self.log.error("Got bad msg: %s"%parent, exc_info=True)
             return
         # pyin_msg = self.session.msg(u'pyin',{u'code':code}, parent=parent)
         # self.iopub_stream.send(pyin_msg)
         # self.session.send(self.iopub_stream, u'pyin', {u'code':code},parent=parent)
         sub = {'dependencies_met' : True, 'engine' : self.ident,
                 'started': datetime.now().strftime(ISO8601)}
         try:
             # allow for not overriding displayhook
             if hasattr(sys.displayhook, 'set_parent'):
                 sys.displayhook.set_parent(parent)
                 sys.stdout.set_parent(parent)
                 sys.stderr.set_parent(parent)
             # exec "f(*args,**kwargs)" in self.user_ns, self.user_ns
             if bound:
                 working = self.user_ns
                 suffix = str(msg_id).replace("-","")
                 prefix = "_"
                 
             else:
                 working = dict()
                 suffix = prefix = "_" # prevent keyword collisions with lambda
             f,args,kwargs = unpack_apply_message(bufs, working, copy=False)
             # if f.fun
             fname = getattr(f, '__name__', 'f')
             
             fname = prefix+fname.strip('<>')+suffix
             argname = prefix+"args"+suffix
             kwargname = prefix+"kwargs"+suffix
             resultname = prefix+"result"+suffix
             
             ns = { fname : f, argname : args, kwargname : kwargs }
             # print ns
             working.update(ns)
             code = "%s=%s(*%s,**%s)"%(resultname, fname, argname, kwargname)
             exec code in working, working
             result = working.get(resultname)
             # clear the namespace
             if bound:
                 for key in ns.iterkeys():
                     self.user_ns.pop(key)
             else:
                 del working
             
             packed_result,buf = serialize_object(result)
             result_buf = [packed_result]+buf
         except:
             exc_content = self._wrap_exception('apply')
             # exc_msg = self.session.msg(u'pyerr', exc_content, parent)
             self.session.send(self.iopub_stream, u'pyerr', exc_content, parent=parent,
                                 ident='%s.pyerr'%self.prefix)
             reply_content = exc_content
             result_buf = []
             
             if exc_content['ename'] == 'UnmetDependency':
                 sub['dependencies_met'] = False
         else:
             reply_content = {'status' : 'ok'}
         
         # put 'ok'/'error' status in header, for scheduler introspection:
         sub['status'] = reply_content['status']
         
         reply_msg = self.session.send(stream, u'apply_reply', reply_content, 
                     parent=parent, ident=ident,buffers=result_buf, subheader=sub)
         
         # if reply_msg['content']['status'] == u'error':
         #     self.abort_queues()
     
     def dispatch_queue(self, stream, msg):
         self.control_stream.flush()
         idents,msg = self.session.feed_identities(msg, copy=False)
         try:
             msg = self.session.unpack_message(msg, content=True, copy=False)
         except:
-            logging.error("Invalid Message", exc_info=True)
+            self.log.error("Invalid Message", exc_info=True)
             return
             
         
         header = msg['header']
         msg_id = header['msg_id']
         if self.check_aborted(msg_id):
             self.aborted.remove(msg_id)
             # is it safe to assume a msg_id will not be resubmitted?
             reply_type = msg['msg_type'].split('_')[0] + '_reply'
             reply_msg = self.session.send(stream, reply_type, 
                         content={'status' : 'aborted'}, parent=msg, ident=idents)
             return
         handler = self.shell_handlers.get(msg['msg_type'], None)
         if handler is None:
-            logging.error("UNKNOWN MESSAGE TYPE: %r"%msg['msg_type'])
+            self.log.error("UNKNOWN MESSAGE TYPE: %r"%msg['msg_type'])
         else:
             handler(stream, idents, msg)
     
     def start(self):
         #### stream mode:
         if self.control_stream:
             self.control_stream.on_recv(self.dispatch_control, copy=False)
             self.control_stream.on_err(printer)
         
         def make_dispatcher(stream):
             def dispatcher(msg):
                 return self.dispatch_queue(stream, msg)
             return dispatcher
         
         for s in self.shell_streams:
             s.on_recv(make_dispatcher(s), copy=False)
             s.on_err(printer)
         
         if self.iopub_stream:
             self.iopub_stream.on_err(printer)
         
         #### while True mode:
         # while True:
         #     idle = True
         #     try:
         #         msg = self.shell_stream.socket.recv_multipart(
         #                     zmq.NOBLOCK, copy=False)
         #     except zmq.ZMQError, e:
         #         if e.errno != zmq.EAGAIN:
         #             raise e
         #     else:
         #         idle=False
         #         self.dispatch_queue(self.shell_stream, msg)
         #             
         #     if not self.task_stream.empty():
         #         idle=False
         #         msg = self.task_stream.recv_multipart()
         #         self.dispatch_queue(self.task_stream, msg)
         #     if idle:
         #         # don't busywait
         #         time.sleep(1e-3)
 
 def make_kernel(int_id, identity, control_addr, shell_addrs, iopub_addr, hb_addrs, 
                 client_addr=None, loop=None, context=None, key=None,
                 out_stream_factory=OutStream, display_hook_factory=DisplayHook):
     """NO LONGER IN USE"""
     # create loop, context, and session:
     if loop is None:
         loop = ioloop.IOLoop.instance()
     if context is None:
         context = zmq.Context()
     c = context
     session = StreamSession(key=key)
     # print (session.key)
     # print (control_addr, shell_addrs, iopub_addr, hb_addrs)
     
     # create Control Stream
     control_stream = zmqstream.ZMQStream(c.socket(zmq.PAIR), loop)
     control_stream.setsockopt(zmq.IDENTITY, identity)
     control_stream.connect(control_addr)
     
     # create Shell Streams (MUX, Task, etc.):
     shell_streams = []
     for addr in shell_addrs:
         stream = zmqstream.ZMQStream(c.socket(zmq.PAIR), loop)
         stream.setsockopt(zmq.IDENTITY, identity)
         stream.connect(addr)
         shell_streams.append(stream)
     
     # create iopub stream:
     iopub_stream = zmqstream.ZMQStream(c.socket(zmq.PUB), loop)
     iopub_stream.setsockopt(zmq.IDENTITY, identity)
     iopub_stream.connect(iopub_addr)
     
     # Redirect input streams and set a display hook.
     if out_stream_factory:
         sys.stdout = out_stream_factory(session, iopub_stream, u'stdout')
         sys.stdout.topic = 'engine.%i.stdout'%int_id
         sys.stderr = out_stream_factory(session, iopub_stream, u'stderr')
         sys.stderr.topic = 'engine.%i.stderr'%int_id
     if display_hook_factory:
         sys.displayhook = display_hook_factory(session, iopub_stream)
         sys.displayhook.topic = 'engine.%i.pyout'%int_id
     
     
     # launch heartbeat
     heart = heartmonitor.Heart(*map(str, hb_addrs), heart_id=identity)
     heart.start()
     
     # create (optional) Client
     if client_addr:
         client = Client(client_addr, username=identity)
     else:
         client = None
     
     kernel = Kernel(id=int_id, session=session, control_stream=control_stream,
             shell_streams=shell_streams, iopub_stream=iopub_stream, 
             client=client, loop=loop)
     kernel.start()
     return loop, c, kernel
 

IPython/zmq/tunnel.py

@@ -1,295 +1,295 b''
 """Basic ssh tunneling utilities."""
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2010  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 from __future__ import print_function
 
 import os,sys, atexit
 from multiprocessing import Process
 from getpass import getpass, getuser
 import warnings
 
 try:
     with warnings.catch_warnings():
         warnings.simplefilter('ignore', DeprecationWarning)
         import paramiko
 except ImportError:
     paramiko = None
 else:
     from forward import forward_tunnel
 
 try:
     from IPython.external import pexpect
 except ImportError:
     pexpect = None
 
 from IPython.zmq.parallel.entry_point import select_random_ports
 
 #-----------------------------------------------------------------------------
 # Code
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Check for passwordless login
 #-----------------------------------------------------------------------------
 
 def try_passwordless_ssh(server, keyfile, paramiko=None):
     """Attempt to make an ssh connection without a password.
     This is mainly used for requiring password input only once
     when many tunnels may be connected to the same server.
     
     If paramiko is None, the default for the platform is chosen.
     """
     if paramiko is None:
         paramiko = sys.platform == 'win32'
     if not paramiko:
         f = _try_passwordless_openssh
     else:
         f = _try_passwordless_paramiko
     return f(server, keyfile)
 
 def _try_passwordless_openssh(server, keyfile):
     """Try passwordless login with shell ssh command."""
     if pexpect is None:
         raise ImportError("pexpect unavailable, use paramiko")
     cmd = 'ssh -f '+ server
     if keyfile:
         cmd += ' -i ' + keyfile
     cmd += ' exit'
     p = pexpect.spawn(cmd)
     while True:
         try:
             p.expect('[Ppassword]:', timeout=.1)
         except pexpect.TIMEOUT:
             continue
         except pexpect.EOF:
             return True
         else:
             return False
 
 def _try_passwordless_paramiko(server, keyfile):
     """Try passwordless login with paramiko."""
     if paramiko is None:
         raise ImportError("paramiko unavailable, use openssh")
     username, server, port = _split_server(server)
     client = paramiko.SSHClient()
     client.load_system_host_keys()
     client.set_missing_host_key_policy(paramiko.WarningPolicy())
     try:
         client.connect(server, port, username=username, key_filename=keyfile,
                look_for_keys=True)
     except paramiko.AuthenticationException:
         return False
     else:
         client.close()
         return True
 
 
 def tunnel_connection(socket, addr, server, keyfile=None, password=None, paramiko=None):
     """Connect a socket to an address via an ssh tunnel.
     
     This is a wrapper for socket.connect(addr), when addr is not accessible
     from the local machine.  It simply creates an ssh tunnel using the remaining args,
     and calls socket.connect('tcp://localhost:lport') where lport is the randomly
     selected local port of the tunnel.
     
     """
     lport = select_random_ports(1)[0]
     transport, addr = addr.split('://')
     ip,rport = addr.split(':')
     rport = int(rport)
     if paramiko is None:
         paramiko = sys.platform == 'win32'
     if paramiko:
         tunnelf = paramiko_tunnel
     else:
         tunnelf = openssh_tunnel
     tunnel = tunnelf(lport, rport, server, remoteip=ip, keyfile=keyfile, password=password)
     socket.connect('tcp://127.0.0.1:%i'%lport)
     return tunnel
 
 def openssh_tunnel(lport, rport, server, remoteip='127.0.0.1', keyfile=None, password=None, timeout=15):
     """Create an ssh tunnel using command-line ssh that connects port lport
     on this machine to localhost:rport on server.  The tunnel
     will automatically close when not in use, remaining open
     for a minimum of timeout seconds for an initial connection.
     
     This creates a tunnel redirecting `localhost:lport` to `remoteip:rport`,
     as seen from `server`.
     
     keyfile and password may be specified, but ssh config is checked for defaults.
     
     Parameters
     ----------
     
         lport : int
             local port for connecting to the tunnel from this machine.
         rport : int
             port on the remote machine to connect to.
         server : str
             The ssh server to connect to. The full ssh server string will be parsed.
             user@server:port
         remoteip : str [Default: 127.0.0.1]
             The remote ip, specifying the destination of the tunnel.
             Default is localhost, which means that the tunnel would redirect
             localhost:lport on this machine to localhost:rport on the *server*.
         
         keyfile : str; path to public key file
             This specifies a key to be used in ssh login, default None.
             Regular default ssh keys will be used without specifying this argument.
         password : str; 
             Your ssh password to the ssh server. Note that if this is left None,
             you will be prompted for it if passwordless key based login is unavailable.
     
     """
     if pexpect is None:
         raise ImportError("pexpect unavailable, use paramiko_tunnel")
     ssh="ssh "
     if keyfile:
         ssh += "-i " + keyfile 
-    cmd = ssh + " -f -L 127.0.0.1:%i:127.0.0.1:%i %s sleep %i"%(lport, rport, server, timeout)
+    cmd = ssh + " -f -L 127.0.0.1:%i:%s:%i %s sleep %i"%(lport, remoteip, rport, server, timeout)
     tunnel = pexpect.spawn(cmd)
     failed = False
     while True:
         try:
             tunnel.expect('[Pp]assword:', timeout=.1)
         except pexpect.TIMEOUT:
             continue
         except pexpect.EOF:
             if tunnel.exitstatus:
                 print (tunnel.exitstatus)
                 print (tunnel.before)
                 print (tunnel.after)
                 raise RuntimeError("tunnel '%s' failed to start"%(cmd))
             else:
                 return tunnel.pid
         else:
             if failed:
                 print("Password rejected, try again")
                 password=None
             if password is None:
                 password = getpass("%s's password: "%(server))
             tunnel.sendline(password)
             failed = True
     
 def _split_server(server):
     if '@' in server:
         username,server = server.split('@', 1)
     else:
         username = getuser()
     if ':' in server:
         server, port = server.split(':')
         port = int(port)
     else:
         port = 22
     return username, server, port
 
 def paramiko_tunnel(lport, rport, server, remoteip='127.0.0.1', keyfile=None, password=None, timeout=15):
     """launch a tunner with paramiko in a subprocess. This should only be used
     when shell ssh is unavailable (e.g. Windows).
     
     This creates a tunnel redirecting `localhost:lport` to `remoteip:rport`,
     as seen from `server`.
     
     If you are familiar with ssh tunnels, this creates the tunnel:
     
     ssh server -L localhost:lport:remoteip:rport
     
     keyfile and password may be specified, but ssh config is checked for defaults.
     
     
     Parameters
     ----------
     
         lport : int
             local port for connecting to the tunnel from this machine.
         rport : int
             port on the remote machine to connect to.
         server : str
             The ssh server to connect to. The full ssh server string will be parsed.
             user@server:port
         remoteip : str [Default: 127.0.0.1]
             The remote ip, specifying the destination of the tunnel.
             Default is localhost, which means that the tunnel would redirect
             localhost:lport on this machine to localhost:rport on the *server*.
         
         keyfile : str; path to public key file
             This specifies a key to be used in ssh login, default None.
             Regular default ssh keys will be used without specifying this argument.
         password : str; 
             Your ssh password to the ssh server. Note that if this is left None,
             you will be prompted for it if passwordless key based login is unavailable.
     
     """
     if paramiko is None:
         raise ImportError("Paramiko not available")
     
     if password is None:
         if not _check_passwordless_paramiko(server, keyfile):
             password = getpass("%s's password: "%(server))
 
     p = Process(target=_paramiko_tunnel, 
             args=(lport, rport, server, remoteip), 
             kwargs=dict(keyfile=keyfile, password=password))
     p.daemon=False
     p.start()
     atexit.register(_shutdown_process, p)
     return p
     
 def _shutdown_process(p):
     if p.isalive():
         p.terminate()
 
 def _paramiko_tunnel(lport, rport, server, remoteip, keyfile=None, password=None):
     """Function for actually starting a paramiko tunnel, to be passed
     to multiprocessing.Process(target=this), and not called directly.
     """
     username, server, port = _split_server(server)
     client = paramiko.SSHClient()
     client.load_system_host_keys()
     client.set_missing_host_key_policy(paramiko.WarningPolicy())
 
     try:
         client.connect(server, port, username=username, key_filename=keyfile,
                        look_for_keys=True, password=password)
 #    except paramiko.AuthenticationException:
 #        if password is None:
 #            password = getpass("%s@%s's password: "%(username, server))
 #            client.connect(server, port, username=username, password=password)
 #        else:
 #            raise
     except Exception as e:
         print ('*** Failed to connect to %s:%d: %r' % (server, port, e))
         sys.exit(1)
 
     # print ('Now forwarding port %d to %s:%d ...' % (lport, server, rport))
 
     try:
         forward_tunnel(lport, remoteip, rport, client.get_transport())
     except KeyboardInterrupt:
         print ('SIGINT: Port forwarding stopped cleanly')
         sys.exit(0)
     except Exception as e:
         print ("Port forwarding stopped uncleanly: %s"%e)
         sys.exit(255)
 
 if sys.platform == 'win32':
     ssh_tunnel = paramiko_tunnel
 else:
     ssh_tunnel = openssh_tunnel
 
     
 __all__ = ['tunnel_connection', 'ssh_tunnel', 'openssh_tunnel', 'paramiko_tunnel', 'try_passwordless_ssh']