pep8'ed logger
updated pip packages
default 'cordloghost' for logging

Change-Id: I2984a76ebe4c1429302e98663105314788a40b7f
diff --git a/containers/xos/pip_requirements.txt b/containers/xos/pip_requirements.txt
index 261e8b7..9d74a34 100644
--- a/containers/xos/pip_requirements.txt
+++ b/containers/xos/pip_requirements.txt
@@ -1,6 +1,6 @@
 pytz==2016.6.1
 Babel==2.3.4
-Django==1.8.14
+Django==1.8.17
 Jinja2==2.8
 Markdown==2.6.6
 MarkupSafe==0.23
@@ -10,7 +10,7 @@
 Routes==2.3.1
 WebOb==1.6.1
 amqp==1.4.9
-ansible==2.2.0.0
+ansible==2.2.1.0
 anyjson==0.3.3
 appdirs==1.4.0
 argparse==1.2.1
@@ -143,7 +143,7 @@
 structlog==16.1.0
 supervisor==3.0b2
 texttable==0.8.7
-tosca-parser==0.6.0
+tosca-parser==0.7.0
 twisted==16.6.0
 unicodecsv==0.14.1
 uritemplate==0.6
diff --git a/xos/xos/logger.py b/xos/xos/logger.py
index 920cf63..271c808 100644
--- a/xos/xos/logger.py
+++ b/xos/xos/logger.py
@@ -1,6 +1,6 @@
 #!/usr/bin/env python
 
-#----------------------------------------------------------------------
+# ----------------------------------------------------------------------
 # Copyright (c) 2008 Board of Trustees, Princeton University
 #
 # Permission is hereby granted, free of charge, to any person obtaining
@@ -13,48 +13,67 @@
 # The above copyright notice and this permission notice shall be
 # included in all copies or substantial portions of the Work.
 #
-# THE WORK IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS 
-# OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF 
-# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND 
+# THE WORK IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
+# OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
 # NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT
-# HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, 
-# WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, 
-# OUT OF OR IN CONNECTION WITH THE WORK OR THE USE OR OTHER DEALINGS 
+# HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
+# WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+# OUT OF OR IN CONNECTION WITH THE WORK OR THE USE OR OTHER DEALINGS
 # IN THE WORK.
-#----------------------------------------------------------------------
+# ----------------------------------------------------------------------
 
-import os, sys
+import os
+import sys
 import traceback
-import logging, logging.handlers
+import time
+import logging
+import logging.handlers
 import logstash
 from xos.config import Config
 
-CRITICAL=logging.CRITICAL
-ERROR=logging.ERROR
-WARNING=logging.WARNING
-INFO=logging.INFO
-DEBUG=logging.DEBUG
+CRITICAL = logging.CRITICAL
+ERROR = logging.ERROR
+WARNING = logging.WARNING
+INFO = logging.INFO
+DEBUG = logging.DEBUG
 
-# a logger that can handle tracebacks 
+# a logger that can handle tracebacks
+
+
 class Logger:
-    def __init__ (self,logfile=None,loggername=None,level=logging.INFO):
-        # Logstash config
+
+    def __init__(self, logfile=None, loggername=None, level=logging.INFO):
+
+        # Logstash config - try as specified explicitly in config
         try:
-            logstash_host,logstash_port = Config().observer_logstash_hostport.split(':')
-            logstash_handler = logstash.LogstashHandler(logstash_host, int(logstash_port), version=1)
+            logstash_host, logstash_port = Config().observer_logstash_hostport.split(':')
+            logstash_handler = logstash.LogstashHandler(
+                logstash_host, int(logstash_port), version=1)
+            # always log at DEBUG level to logstash
+            logstash_handler.setLevel(logging.DEBUG)
         except:
             logstash_handler = None
 
+        # try using the default cordloghost:5617
+        if not logstash_handler:
+            try:
+                logstash_handler = logstash.LogstashHandler(
+                    "cordloghost", 5617, version=1)
+                # always log at DEBUG level to logstash
+                logstash_handler.setLevel(logging.DEBUG)
+            except:
+                logstash_handler = None
+
         # default is to locate loggername from the logfile if avail.
         if not logfile:
             try:
-                logfile = Config().observer_log_file
+                logfile = Config().logfile
             except:
                 logfile = "/var/log/xos.log"
 
-        # allow config-file override of log level
-
-        level_str = getattr(Config(), "observer_log_level", None)
+        # allow config-file override of console/logfile level
+        level_str = getattr(Config(), "log_level", None)
         if level_str:
             level_str = level_str.lower()
 
@@ -70,73 +89,80 @@
         if (logfile == "console"):
             loggername = "console"
             handler = logging.StreamHandler()
+
         else:
             if not loggername:
-                loggername=os.path.basename(logfile)
+                loggername = os.path.basename(logfile)
             try:
-                handler=logging.handlers.RotatingFileHandler(logfile,maxBytes=1000000, backupCount=5)
+                handler = logging.handlers.RotatingFileHandler(
+                    logfile, maxBytes=1000000, backupCount=5)
             except IOError:
                 # This is usually a permissions error becaue the file is
                 # owned by root, but httpd is trying to access it.
-                tmplogfile=os.getenv("TMPDIR", "/tmp") + os.path.sep + os.path.basename(logfile)
+                tmplogfile = os.getenv(
+                    "TMPDIR", "/tmp") + os.path.sep + os.path.basename(logfile)
                 # In strange uses, 2 users on same machine might use same code,
                 # meaning they would clobber each others files
                 # We could (a) rename the tmplogfile, or (b)
                 # just log to the console in that case.
                 # Here we default to the console.
-                if os.path.exists(tmplogfile) and not os.access(tmplogfile,os.W_OK):
+                if os.path.exists(tmplogfile) and not os.access(
+                        tmplogfile, os.W_OK):
                     loggername = loggername + "-console"
                     handler = logging.StreamHandler()
                 else:
-                    handler=logging.handlers.RotatingFileHandler(tmplogfile,maxBytes=1000000, backupCount=5)
+                    handler = logging.handlers.RotatingFileHandler(
+                        tmplogfile, maxBytes=1000000, backupCount=5)
 
-        handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))
-        self.logger=logging.getLogger(loggername)
+        handler.setFormatter(logging.Formatter(
+            "%(asctime)s - %(levelname)s - %(message)s"))
+        self.logger = logging.getLogger(loggername)
         self.logger.setLevel(level)
-        # check if logger already has the handler we're about to add
-        handler_exists = False
-        logstash_handler_exists = False
 
+        # check if logger already has the handler we're about to add
         if not len(self.logger.handlers):
             self.logger.addHandler(handler)
 
             if (logstash_handler):
                 self.logger.addHandler(logstash_handler)
 
-        self.loggername=loggername
+        self.loggername = loggername
 
-    def setLevel(self,level):
+    def setLevel(self, level):
         self.logger.setLevel(level)
 
     # shorthand to avoid having to import logging all over the place
     def setLevelDebug(self):
         self.logger.setLevel(logging.DEBUG)
 
-    def debugEnabled (self):
+    def debugEnabled(self):
         return self.logger.getEffectiveLevel() == logging.DEBUG
 
     # define a verbose option with s/t like
-    # parser.add_option("-v", "--verbose", action="count", dest="verbose", default=0)
+    # parser.add_option("-v", "--verbose", action="count",
+    #   dest="verbose", default=0)
     # and pass the coresponding options.verbose to this method to adjust level
-    def setLevelFromOptVerbose(self,verbose):
-        if verbose==0:
+    def setLevelFromOptVerbose(self, verbose):
+        if verbose == 0:
             self.logger.setLevel(logging.WARNING)
-        elif verbose==1:
+        elif verbose == 1:
             self.logger.setLevel(logging.INFO)
-        elif verbose>=2:
+        elif verbose >= 2:
             self.logger.setLevel(logging.DEBUG)
     # in case some other code needs a boolean
-    def getBoolVerboseFromOpt(self,verbose):
-        return verbose>=1
-    def getBoolDebugFromOpt(self,verbose):
-        return verbose>=2
+
+    def getBoolVerboseFromOpt(self, verbose):
+        return verbose >= 1
+
+    def getBoolDebugFromOpt(self, verbose):
+        return verbose >= 2
 
     ####################
 
-    def extract_context(self,cur):
+    def extract_context(self, cur):
         try:
-            observer_name=Config().observer_name
-            cur['synchronizer_name']=observer_name
+            observer_name = Config().observer_name
+            cur['synchronizer_name'] = observer_name
         except:
             pass
 
@@ -144,56 +170,68 @@
         return cur
 
     def sanitize_extra_args(self, extra):
-        illegal_keys = logging.LogRecord(None,None,None,None,None,None,None,None).__dict__.keys()
+        illegal_keys = logging.LogRecord(
+            None, None, None, None, None, None, None, None).__dict__.keys()
         for k in illegal_keys:
             try:
                 del extra[k]
-                self.logger.warn("*** WARNING: Dropped field %s from extra args ***")
+                self.logger.warn(
+                    "*** WARNING: Dropped field %s from extra args ***")
             except KeyError:
                 pass
 
     def info(self, msg, extra={}):
-        extra = self.extract_context(extra) 
+        extra = self.extract_context(extra)
         self.logger.info(msg, extra=extra)
 
     def debug(self, msg, extra={}):
-        extra = self.extract_context(extra) 
+        extra = self.extract_context(extra)
         self.logger.debug(msg, extra=extra)
-        
+
     def warn(self, msg, extra={}):
-        extra = self.extract_context(extra) 
+        extra = self.extract_context(extra)
         self.logger.warn(msg, extra=extra)
 
     # some code is using logger.warn(), some is using logger.warning()
     def warning(self, msg, extra={}):
-        extra = self.extract_context(extra) 
-        self.logger.warning(msg,extra=extra)
-   
+        extra = self.extract_context(extra)
+        self.logger.warning(msg, extra=extra)
+
     def error(self, msg, extra={}):
-        extra = self.extract_context(extra) 
-        self.logger.error(msg, extra=extra)    
- 
+        extra = self.extract_context(extra)
+        self.logger.error(msg, extra=extra)
+
     def critical(self, msg, extra={}):
-        extra = self.extract_context(extra) 
+        extra = self.extract_context(extra)
         self.logger.critical(msg, extra=extra)
 
     # logs an exception - use in an except statement
-    def log_exc(self,message, extra={}):
-        extra = self.extract_context(extra) 
-        self.error("%s BEG TRACEBACK"%message+"\n"+traceback.format_exc().strip("\n"), extra=extra)
-        self.error("%s END TRACEBACK"%message, extra=extra)
-    
-    def log_exc_critical(self,message, extra={}):
-        extra = self.extract_context(extra) 
-        self.critical("%s BEG TRACEBACK"%message+"\n"+traceback.format_exc().strip("\n"), extra=extra)
-        self.critical("%s END TRACEBACK"%message, extra=extra)
-    
+    def log_exc(self, message, extra={}):
+        extra = self.extract_context(extra)
+        self.error(
+            "%s BEG TRACEBACK" %
+            message +
+            "\n" +
+            traceback.format_exc().strip("\n"),
+            extra=extra)
+        self.error("%s END TRACEBACK" % message, extra=extra)
+
+    def log_exc_critical(self, message, extra={}):
+        extra = self.extract_context(extra)
+        self.critical(
+            "%s BEG TRACEBACK" %
+            message +
+            "\n" +
+            traceback.format_exc().strip("\n"),
+            extra=extra)
+        self.critical("%s END TRACEBACK" % message, extra=extra)
+
     # for investigation purposes, can be placed anywhere
-    def log_stack(self,message, extra={}):
-        extra = self.extract_context(extra) 
-        to_log="".join(traceback.format_stack())
-        self.info("%s BEG STACK"%message+"\n"+to_log,extra=extra)
-        self.info("%s END STACK"%message,extra=extra)
+    def log_stack(self, message, extra={}):
+        extra = self.extract_context(extra)
+        to_log = "".join(traceback.format_stack())
+        self.info("%s BEG STACK" % message + "\n" + to_log, extra=extra)
+        self.info("%s END STACK" % message, extra=extra)
 
     def enable_console(self, stream=sys.stdout):
         formatter = logging.Formatter("%(message)s")
@@ -208,14 +246,17 @@
 error_logger = Logger(loggername='error', level=logging.ERROR)
 critical_logger = Logger(loggername='critical', level=logging.CRITICAL)
 logger = info_logger
-observer_logger = Logger(logfile='/var/log/observer.log', loggername='observer', level=logging.DEBUG)
+observer_logger = Logger(
+    logfile='/var/log/observer.log',
+    loggername='observer',
+    level=logging.DEBUG)
 ########################################
-import time
+
 
 def profile(logger):
     """
     Prints the runtime of the specified callable. Use as a decorator, e.g.,
-    
+
     @profile(logger)
     def foo(...):
         ...
@@ -226,24 +267,27 @@
             result = callable(*args, **kwds)
             end = time.time()
             args = map(str, args)
-            args += ["%s = %s" % (name, str(value)) for (name, value) in kwds.iteritems()]
+            args += ["%s = %s" % (name, str(value))
+                     for (name, value) in kwds.iteritems()]
             # should probably use debug, but then debug is not always enabled
-            logger.info("PROFILED %s (%s): %.02f s" % (callable.__name__, ", ".join(args), end - start))
+            logger.info("PROFILED %s (%s): %.02f s" %
+                        (callable.__name__, ", ".join(args), end - start))
             return result
         return wrapper
     return logger_profile
 
 
-if __name__ == '__main__': 
+if __name__ == '__main__':
     print 'testing logging into logger.log'
-    logger1=Logger('logger.log', loggername='std(info)')
-    logger2=Logger('logger.log', loggername='error', level=logging.ERROR)
-    logger3=Logger('logger.log', loggername='debug', level=logging.DEBUG)
-    
-    for (logger,msg) in [ (logger1,"std(info)"),(logger2,"error"),(logger3,"debug")]:
-        
-        print "====================",msg, logger.logger.handlers
-   
+    logger1 = Logger('logger.log', loggername='std(info)')
+    logger2 = Logger('logger.log', loggername='error', level=logging.ERROR)
+    logger3 = Logger('logger.log', loggername='debug', level=logging.DEBUG)
+
+    for (logger, msg) in [(logger1, "std(info)"),
+                          (logger2, "error"), (logger3, "debug")]:
+
+        print "====================", msg, logger.logger.handlers
+
         logger.enable_console()
         logger.critical("logger.critical")
         logger.error("logger.error")
@@ -252,13 +296,12 @@
         logger.debug("logger.debug")
         logger.setLevel(logging.DEBUG)
         logger.debug("logger.debug again")
-    
+
         @profile(logger)
-        def sleep(seconds = 1):
+        def sleep(seconds=1):
             time.sleep(seconds)
 
         logger.info('console.info')
         sleep(0.5)
         logger.setLevel(logging.DEBUG)
         sleep(0.25)
-