add initial logging support

This logging infrastructure in cloudinit:
- uses python logging
- allows user supplied config of logging.config.fileConfig format to be
  supplied in /etc/cloud/cloud.cfg or in cloud_config by user data.
- by default, tries to use syslog, if that is not available, writes directly to
  /var/log/cloud-init.log (syslog will not be available yet when cloud-init
  runs)
- when using syslog, the doc/21-cloudinit.conf file provides a rsyslogd
  file to be placed in /etc/rsyslog.d/ that will file [CLOUDINIT] messages
  to /var/log/cloud-init.log

8 files changed, 184 insertions, 26 deletions

diff --git a/cloud-init-cfg.py b/cloud-init-cfg.py
index 8684c532..2ef9bb04 100755
--- a/cloud-init-cfg.py
+++ b/cloud-init-cfg.py
@@ -19,6 +19,9 @@
 
 import sys
 import cloudinit
+import cloudinit.CloudConfig
+import logging
+import os
 
 def Usage(out = sys.stdout):
     out.write("Usage: %s name\n" % sys.argv[0])
@@ -33,8 +36,11 @@ def main():
     name=sys.argv[1]
     run_args=sys.argv[2:]
 
-    import cloudinit.CloudConfig
-    import os
+    cloudinit.logging_set_from_cfg_file()
+    log = logging.getLogger()
+    log.info("cloud-init-cfg %s" % sys.argv[1:])
+
+    cloud = cloudinit.CloudInit()
 
     cfg_path = cloudinit.cloud_config
     cfg_env_name = cloudinit.cfg_env_name
diff --git a/cloud-init-run-module.py b/cloud-init-run-module.py
index f7299f46..4ec79ff9 100755
--- a/cloud-init-run-module.py
+++ b/cloud-init-run-module.py
@@ -19,6 +19,7 @@
 
 import sys
 import cloudinit
+import logging
 
 def Usage(out = sys.stdout):
     out.write("Usage: cloud-init-run-module freq sem-name mod-name [args]\n")
@@ -33,6 +34,9 @@ def main():
     (freq,semname,modname)=sys.argv[1:4]
     run_args=sys.argv[4:]
 
+    cloudinit.logging_set_from_cfg_file()
+    log = logging.getLogger()
+    log.info("cloud-init-run-module %s" % sys.argv[1:])
     cloud = cloudinit.CloudInit()
     try:
         cloud.get_data_source()
diff --git a/cloud-init.py b/cloud-init.py
index 15a98957..924f3350 100755
--- a/cloud-init.py
+++ b/cloud-init.py
@@ -23,6 +23,7 @@ import sys
 import cloudinit
 import cloudinit.util as util
 import time
+import logging
 
 def warn(str):
     sys.stderr.write(str)
@@ -37,9 +38,14 @@ def main():
        warn("unable to open /proc/uptime\n")
        uptime = "na"
 
-    sys.stderr.write("cloud-init running: %s. up %s seconds\n" % (now, uptime))
+    msg = "cloud-init running: %s. up %s seconds\n" % (now, uptime)
+    sys.stderr.write(msg)
     sys.stderr.flush()
 
+    cloudinit.logging_set_from_cfg_file()
+    log = logging.getLogger()
+    log.info(msg)
+
     # cache is not instance specific, so it has to be purged
     cloudinit.purge_cache()
 
diff --git a/cloud.cfg b/cloud.cfg
index 898a8b62..3509f5b4 100644
--- a/cloud.cfg
+++ b/cloud.cfg
@@ -1,3 +1,11 @@
 cloud_type: auto
 user: ubuntu
 disable_root: 1
+
+cloud_config_modules:
+ - apt-update-upgrade
+ - config-misc
+ - config-mounts
+ - config-puppet
+ - config-ssh
+ - disable-ec2-metadata
diff --git a/cloudinit/DataSourceEc2.py b/cloudinit/DataSourceEc2.py
index ad88a704..ebee61c6 100644
--- a/cloudinit/DataSourceEc2.py
+++ b/cloudinit/DataSourceEc2.py
@@ -126,14 +126,14 @@ class DataSourceEc2(DataSource.DataSource):
                 reason = "url error [%s]" % e.reason
     
             if x == 0:
-               sys.stderr.write("waiting for metadata service at %s\n" % url)
+                cloudinit.log.warning("waiting for metadata service at %s\n" % url)
 
-            sys.stderr.write("  %s [%02s/%s]: %s\n" %
-                             (time.strftime("%H:%M:%S"), x+1, sleeps, reason))
+            cloudinit.log.warning("  %s [%02s/%s]: %s\n" %
+                (time.strftime("%H:%M:%S"), x+1, sleeps, reason))
             time.sleep(sleeptime)
 
-        sys.stderr.write("giving up on md after %i seconds\n" %
-                         int(time.time()-starttime))
+        log.critical("giving up on md after %i seconds\n" %
+                  int(time.time()-starttime))
         return False
 
     def get_public_ssh_keys(self):
diff --git a/cloudinit/__init__.py b/cloudinit/__init__.py
index a48c8ab3..c10f5add 100644
--- a/cloudinit/__init__.py
+++ b/cloudinit/__init__.py
@@ -18,17 +18,6 @@
 #    along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
-import os
-from   configobj import ConfigObj
-
-import cPickle
-import sys
-import os.path
-import errno
-import pwd
-import subprocess
-import yaml
-
 datadir = '/var/lib/cloud/data'
 semdir = '/var/lib/cloud/sem'
 pluginsdir = datadir + '/plugins'
@@ -41,9 +30,133 @@ data_source_cache = cachedir + '/obj.pkl'
 system_config = '/etc/cloud/cloud.cfg'
 cfg_env_name = "CLOUD_CFG"
 
+cfg_builtin = """
+cloud_type: auto
+user: ubuntu
+disable_root: 1
+
+cloud_config_modules:
+ - apt-update-upgrade
+ - config-misc
+ - config-mounts
+ - config-puppet
+ - config-ssh
+ - disable-ec2-metadata
+
+log_cfg: built_in
+"""
+
+def_log_file = '/var/log/cloud-init.log'
+logger_name = "cloudinit"
+
+built_in_log_base = """
+[loggers]
+keys=root,cloudinit
+
+[handlers]
+keys=consoleHandler,cloudLogHandler
+
+[formatters]
+keys=simpleFormatter,arg0Formatter
+
+[logger_root]
+level=DEBUG
+handlers=consoleHandler,cloudLogHandler
+
+[logger_cloudinit]
+level=DEBUG
+qualname=cloudinit
+handlers=
+propagate=1
+
+[handler_consoleHandler]
+class=StreamHandler
+level=WARNING
+formatter=arg0Formatter
+args=(sys.stderr,)
+
+[formatter_arg0Formatter]
+format=%(asctime)s - %(filename)s[%(levelname)s]: %(message)s
+
+[formatter_simpleFormatter]
+format=[CLOUDINIT] %(asctime)s - %(filename)s[%(levelname)s]: %(message)s
+datefmt=
+
+"""
+
+built_in_log_clougLogHandlerLog="""
+[handler_cloudLogHandler]
+class=FileHandler
+level=DEBUG
+formatter=simpleFormatter
+args=('__CLOUDINIT_LOGGER_FILE__',)
+"""
+
+built_in_log_cloudLogHandlerSyslog= """
+[handler_cloudLogHandler]
+class=handlers.SysLogHandler
+level=DEBUG
+formatter=simpleFormatter
+args=("/dev/log", handlers.SysLogHandler.LOG_USER)
+"""
+
+
+import os
+from   configobj import ConfigObj
+
+import cPickle
+import sys
+import os.path
+import errno
+import pwd
+import subprocess
+import yaml
+import util
+import logging
+import logging.config
+import StringIO
+
+class NullHandler(logging.Handler):
+	def emit(self,record): pass
+
+log = logging.getLogger(logger_name)
+log.addHandler(NullHandler())
+
+def logging_set_from_cfg_file(cfg_file=system_config):
+    logging_set_from_cfg(util.get_base_cfg(cfg_file))
+
+def logging_set_from_cfg(cfg, logfile=None):
+    if logfile is None:
+        try:
+            open(def_log_file,"a").close()
+            logfile = def_log_file
+        except IOError as e:
+            if e.errno == errno.EACCES:
+                logfile = "/dev/null"
+            else: raise
+    
+    logcfg=util.get_cfg_option_str(cfg, "log_cfg", "built_in")
+    failsafe = "%s\n%s" % (built_in_log_base, built_in_log_clougLogHandlerLog)
+    builtin = False
+    if logcfg.lower() == "built_in":
+        logcfg = "%s\n%s" % (built_in_log_base, built_in_log_cloudLogHandlerSyslog)
+        builtin = True
+
+    logcfg=logcfg.replace("__CLOUDINIT_LOGGER_FILE__",logfile)
+    try:
+        logging.config.fileConfig(StringIO.StringIO(logcfg))
+        print "using logfile = %s" % logcfg
+        return
+    except:
+        if not builtin:
+            sys.stderr.write("Warning, setting config.fileConfig failed\n")
+
+    print "trying with failsafe"
+    failsafe=failsafe.replace("__CLOUDINIT_LOGGER_FILE__",logfile)
+    logging.config.fileConfig(StringIO.StringIO(failsafe))
+
 import DataSourceEc2
 import UserDataHandler
-import util
 
 class CloudInit:
     datasource_map = {
@@ -56,13 +169,14 @@ class CloudInit:
     part_handlers = { }
     old_conffile = '/etc/ec2-init/ec2-config.cfg'
 
-    def __init__(self):
+    def __init__(self, sysconfig=system_config):
         self.part_handlers = {
             'text/x-shellscript' : self.handle_user_script,
             'text/cloud-config' : self.handle_cloud_config,
             'text/upstart-job' : self.handle_upstart_job,
             'text/part-handler' : self.handle_handler
         }
+        self.sysconfig=sysconfig
         self.cfg=self.read_cfg()
 
     def read_cfg(self):
@@ -71,7 +185,7 @@ class CloudInit:
 
         conf = { }
         try:
-	        stream = file(system_config)
+	        stream = file(self.sysconfig)
 	        conf = yaml.load(stream)
 	        stream.close()
         except:
@@ -142,9 +256,11 @@ class CloudInit:
                 if s.get_data():
                     self.datasource = s
                     self.datasource_name = ds
+                    log.debug("found data source %s" % ds)
                     return True
             except Exception as e:
                 pass
+        log.critical("Could not find data source")
         raise Exception("Could not find data source")
 
     def get_userdata(self):
diff --git a/cloudinit/util.py b/cloudinit/util.py
index 1c838fa8..79115355 100644
--- a/cloudinit/util.py
+++ b/cloudinit/util.py
@@ -20,12 +20,23 @@ import os
 import errno
 import subprocess
 from Cheetah.Template import Template
+import cloudinit
 
 def read_conf(fname):
-	stream = file(fname)
-	conf = yaml.load(stream)
-	stream.close()
-	return conf
+    try:
+	    stream = open(fname,"r")
+	    conf = yaml.load(stream)
+	    stream.close()
+	    return conf
+    except IOError as e:
+        if e.errno == errno.ENOENT:
+            return { }
+        raise
+
+def get_base_cfg(cfgfile=cloudinit.system_config):
+    syscfg = read_conf(cfgfile)
+    builtin = yaml.load(cloudinit.cfg_builtin)
+    return(mergedict(syscfg,builtin))
 
 def get_cfg_option_bool(yobj, key, default=False):
     if not yobj.has_key(key): return default
diff --git a/doc/21-cloudinit.conf b/doc/21-cloudinit.conf
new file mode 100644
index 00000000..0a2d7688
--- /dev/null
+++ b/doc/21-cloudinit.conf
@@ -0,0 +1,7 @@
+# Log cloudinit generated log messages to file
+:syslogtag, isequal, "[CLOUDINIT]" /var/log/cloud-init.log
+
+# Uncomment the following to stop logging anything that matches the last rule.
+# Doing this will stop logging kernel generated UFW log messages to the file
+# normally containing kern.* messages (eg, /var/log/kern.log)
+& ~