Logbook for component state tracking.

zipline/components/feed.py

@@ -42,7 +42,7 @@ class Feed(Aggregate):
 
     @property
     def draining(self):
-        return self.state == DRAINING
+        return self.state == AGGREGATE_STATES.DRAINING
 
     # -------
     # Sockets

zipline/components/tradesimulation.py

@@ -1,4 +1,4 @@
-import logging
+import logbook
 import datetime
 
 import zipline.protocol as zp
@@ -8,7 +8,7 @@ from zipline.core.component import Component
 from zipline.finance.trading import TransactionSimulator
 from zipline.utils.protocol_utils import  ndict
 
-LOGGER = logging.getLogger('ZiplineLogger')
+log = logbook.Logger('TradeSimulation')
 
 class TradeSimulationClient(Component):
 
@@ -74,7 +74,7 @@ class TradeSimulationClient(Component):
                 self.finish_simulation()
 
     def finish_simulation(self):
-        LOGGER.info("Client is DONE!")
+        log.info("TradeSimulation is Done")
         # signal the performance tracker that the simulation has
         # ended. Perf will internally calculate the full risk report.
         self.perf.handle_simulation_end()

zipline/core/component.py

@@ -7,7 +7,7 @@ import sys
 import uuid
 import time
 import socket
-import logging
+import logbook
 import traceback
 import humanhash
 from setproctitle import setproctitle
@@ -23,7 +23,7 @@ from zipline.utils.gpoll import _Poller as GeventPoller
 from zipline.protocol import CONTROL_PROTOCOL, COMPONENT_STATE, \
     COMPONENT_FAILURE, CONTROL_FRAME
 
-LOGGER = logging.getLogger('ZiplineLogger')
+log = logbook.Logger('Component')
 
 from zipline.exceptions import ComponentNoInit
 from zipline.transitions import WorkflowMeta
@@ -357,7 +357,7 @@ class Component(object):
         #notify internal work look that we're done
         self.done = True # TODO: use state flag
 
-        LOGGER.info("[%s] DONE" % self.get_id)
+        log.info("[%s] DONE" % self.get_id)
 
     # -----------
     #  Messaging

zipline/core/host.py

@@ -1,4 +1,4 @@
-import logging
+import logbook
 import datetime
 
 from component import Component
@@ -8,7 +8,7 @@ from zipline.components import Feed, Merge, PassthroughTransform, \
     DataSource
 from zipline.protocol import CONTROL_PROTOCOL, COMPONENT_STATE
 
-LOGGER = logging.getLogger('ZiplineLogger')
+log = logbook.Logger('Host')
 
 class ComponentHost(Component):
     """
@@ -89,7 +89,7 @@ class ComponentHost(Component):
         """
         Setup the sync socket and poller. ( Bind )
         """
-        #LOGGER.debug("Connecting sync server.")
+        #log.debug("Connecting sync server.")
 
         self.sync_socket = self.context.socket(self.zmq.REP)
         self.sync_socket.bind(self.addresses['sync_address'])
@@ -100,11 +100,11 @@ class ComponentHost(Component):
         self.sockets.append(self.sync_socket)
 
     def open(self):
-        LOGGER.info('== Roll Call ==\n')
+        log.info('== Roll Call ==\n')
         for component in self.components.itervalues():
-            LOGGER.info(component)
+            log.info(component)
 
-        LOGGER.info('== End Roll Call ==\n')
+        log.info('== End Roll Call ==\n')
 
         for component in self.components.itervalues():
             self.launch_component(component)
@@ -117,7 +117,7 @@ class ComponentHost(Component):
         """
 
         if len(self.components) == 0:
-            LOGGER.info("Component register is empty.")
+            log.info("Component register is empty.")
             return False
 
         return True
@@ -138,14 +138,15 @@ class ComponentHost(Component):
                 except ValueError as exc:
                     self.signal_exception(exc)
 
-                if status == str(CONTROL_PROTOCOL.DONE): # TODO: other way around
-                    LOGGER.debug("{id} is DONE".format(id=sync_id))
+                # TODO: other way around
+                if status == str(CONTROL_PROTOCOL.DONE):
+                    #log.debug("Component claims done: {id}".format(id=sync_id))
                     self.unregister_component(sync_id)
                     self.state_flag = COMPONENT_STATE.DONE
                 else:
                     self.sync_register[sync_id] = datetime.datetime.utcnow()
 
-                #qutil.LOGGER.info("confirmed {id}".format(id=msg))
+                #log.info("confirmed {id}".format(id=msg))
                 # send synchronization reply
                 self.sync_socket.send('ack', self.zmq.NOBLOCK)
 

zipline/core/monitor.py

@@ -2,7 +2,7 @@ import zmq
 import time
 import gevent
 import itertools
-import logging
+import logbook
 import gevent_zeromq
 
 from collections import OrderedDict
@@ -122,6 +122,9 @@ class UnknownChatter(Exception):
         return """Component calling itself "%s" talking on unexpected channel"""\
             % self.named
 
+
+log = logbook.Logger('Controller')
+
 class Controller(object):
     """
     A N to M messaging system for inter component communication.
@@ -133,9 +136,6 @@ class Controller(object):
                          the individual components.
                          :func message_sender: .
 
-    :param logging: Logging interface for tracking broker state
-        Defaults to None
-
     Topology is the set of components we expect to show up.
     States are the transitions the sytems go through. The
     simplest is from RUNNING -> NOT RUNNING .
@@ -159,7 +159,7 @@ class Controller(object):
     debug = False
     period = 1
 
-    def __init__(self, pub_socket, route_socket, logger = None):
+    def __init__(self, pub_socket, route_socket):
 
         self.context    = None
         self.zmq        = None
@@ -182,12 +182,6 @@ class Controller(object):
 
         self.error_replay = OrderedDict()
 
-        if logger:
-            self.logging = logger
-        else:
-            default_logger = logging.getLogger('ZiplineLogger')
-            self.logging = default_logger
-
     def init_zmq(self, flavor):
 
         assert self.zmq_flavor in ['thread', 'mp', 'green']
@@ -240,9 +234,9 @@ class Controller(object):
         old, self._state = self._state, new
 
         if (old, new) not in state_transitions:
-            raise RuntimeError("[Controller] Invalid State Transition : %s -> %s" %(old, new))
+            raise RuntimeError("Invalid State Transition : %s -> %s" %(old, new))
         else:
-            self.logging.info("[Controller] State Transition : %s -> %s" %(old, new))
+            log.error("State Transition : %s -> %s" %(old, new))
 
     def run(self):
         self.running = True
@@ -251,13 +245,13 @@ class Controller(object):
         try:
             return self._poll() # use a python loop
         except KeyboardInterrupt:
-            self.logging.info('Shutdown event loop')
+            log.debug('Shutdown event loop')
 
     def log_status(self):
         """
         Snapshot of the tracked components at every period.
         """
-        #self.logging.info("[Controller] Tracking : %s" % ([c for c in self.tracked],))
+        #log.info("Tracking component : %s" % ([c for c in self.tracked],))
         pass
 
     def replay_errors(self):
@@ -366,11 +360,11 @@ class Controller(object):
                             self.handle_recv(buffer[:])
                             buffer = []
                     except INVALID_CONTROL_FRAME:
-                        self.logging.error('Invalid frame', rawmessage)
+                        log.error('Invalid frame', rawmessage)
                         pass
 
                 if socks.get(self.cancel) == self.zmq.POLLIN:
-                    self.logging.info('[Controller] Received Cancellation')
+                    log.info('Received Cancellation')
                     rawmessage = self.cancel.recv()
                     self.cancel.send('')
                     self.shutdown(soft=True)
@@ -430,7 +424,7 @@ class Controller(object):
         if self.state is CONTROL_STATES.TERMINATE:
             return
 
-        self.logging.info('[Controller] Now Tracking "%s" ' % component)
+        log.info(' Now Tracking "%s" ' % component)
 
         universal = self.new_universal
         init_handlers = {
@@ -452,7 +446,7 @@ class Controller(object):
     def fail_universal(self):
         pass
         # TODO: this requires higher order functionality
-        #self.logging.error('[Controller] System in exception state, shutting down')
+        #log.error('System in exception state, shutting down')
         #self.shutdown(soft=True)
 
     def fail(self, component):
@@ -463,7 +457,7 @@ class Controller(object):
         fail_handlers = { }
 
         if component in self.topology or self.freeform:
-            self.logging.info('[Controller] Component "%s" timed out' % component)
+            log.error('Component "%s" timed out' % component)
             self.tracked.remove(component)
             fail_handlers.get(component, universal)()
 
@@ -472,7 +466,7 @@ class Controller(object):
     # -------------------
 
     def done(self, component):
-        self.logging.info('[Controller] Component "%s" done.' % component)
+        log.info('Component "%s" signaled done.' % component)
 
     # --------------
     # Error Handling
@@ -482,7 +476,7 @@ class Controller(object):
         """
         Shutdown the system on failure.
         """
-        self.logging.error('[Controller] System in exception state, shutting down')
+        log.error('System in exception state, shutting down')
         self.shutdown(soft=True)
 
     def exception(self, component, failure):
@@ -491,7 +485,7 @@ class Controller(object):
 
         if component in self.topology or self.freeform:
             self.error_replay[(component, time.time())] = failure
-            self.logging.error('[Controller] Component "%s" in exception state' % component)
+            log.error('Component in exception state: %s' % component)
 
             exception_handlers.get(component, universal)()
         else:
@@ -517,8 +511,9 @@ class Controller(object):
                 self.responses.add(identity)
             else:
                 # Otherwise its something weird and we don't know
-                # what to do so just say so
-                self.logging.error("Weird stuff happened: %s" % msg)
+                # what to do so just say so, probably line noise
+                # from ZeroMQ
+                log.error("Weird stuff happened: %s" % msg)
 
         # A component is telling us it failed, and how
         if id is CONTROL_PROTOCOL.EXCEPTION:
@@ -572,7 +567,7 @@ class Controller(object):
 
     def do_error_replay(self):
         for (component, time), error in self.error_replay.iteritems():
-            self.logging.info('[Controller] Error Log for -- %s --:\n%s' %
+            log.info('Error Log for -- %s --:\n%s' %
                 (component, error))
 
     def shutdown(self, hard=False, soft=True, context=None):
@@ -587,7 +582,7 @@ class Controller(object):
         if hard:
             self.state = CONTROL_STATES.TERMINATE
 
-            self.logging.info('[Controller] Hard Shutdown')
+            log.info('Hard Shutdown')
 
             #for asoc in self.associated:
                 #asoc.close()
@@ -595,7 +590,7 @@ class Controller(object):
         if soft:
             self.state = CONTROL_STATES.TERMINATE
 
-            self.logging.info('[Controller] Soft Shutdown')
+            log.info('Soft Shutdown')
             self.send_softkill()
 
             #for asoc in self.associated:

zipline/lines.py

@@ -60,8 +60,6 @@ before invoking simulate.
                           +---------------------------------+
 """
 
-import logging
-
 import zipline.utils.factory as factory
 
 from zipline.components import DataSource
@@ -73,8 +71,6 @@ from zipline.core.devsimulator import Simulator
 from zipline.core.monitor import Controller
 from zipline.finance.trading import SIMULATION_STYLE
 
-LOGGER = logging.getLogger('ZiplineLogger')
-
 class SimulatedTrading(object):
     """
     Zipline with::
@@ -133,7 +129,6 @@ class SimulatedTrading(object):
         self.con = Controller(
             sockets[6],
             sockets[7],
-            logger = LOGGER
         )
 
         self.con.cancel_socket = self.allocator.lease(1)[0]

zipline/utils/logger.py

@@ -3,6 +3,7 @@ Small classes to assist with timezone calculations, LOGGER configuration,
 and other common operations.
 """
 
+# DEPRECATED DO NOT USE
 
 import logging
 import logging.config