send welcome message after logging has been applied

in the 'cloud-init init' stages, we want the welcome message to get to the
correct output as specified by the system's configuration.  Ie, if the
local /etc/cloud.config.d had 'output' or 'log_cfg' settings we want those
to be able to affect the welcome message also.

In normal operation, nothing else will go to stdout or stderr before this,
and likely/hopefully nothing terribly important to the logs.

bin/cloud-init

@@ -82,16 +82,22 @@ def print_exc(msg=''):
     sys.stderr.write("\n")
 
 
-def welcome(action):
+def welcome(action, msg=None):
+    if not msg:
+        msg = welcome_format(action)
+    util.multi_log("%s\n" % (msg),
+                   console=False, stderr=True, log=LOG)
+    return msg
+
+
+def welcome_format(action):
     tpl_params = {
         'version': version.version_string(),
         'uptime': util.uptime(),
         'timestamp': util.time_rfc2822(),
         'action': action,
     }
-    tpl_msg = templater.render_string(WELCOME_MSG_TPL, tpl_params)
-    util.multi_log("%s\n" % (tpl_msg),
-                   console=False, stderr=True)
+    return templater.render_string(WELCOME_MSG_TPL, tpl_params)
 
 
 def extract_fns(args):
@@ -154,7 +160,7 @@ def main_init(name, args):
     #    the modules objects configuration
     # 10. Run the modules for the 'init' stage
     # 11. Done!
-    welcome(name)
+    w_msg = welcome_format(name)
     init = stages.Init(deps)
     # Stage 1
     init.read_cfg(extract_fns(args))
@@ -174,6 +180,12 @@ def main_init(name, args):
                     " longer be active shortly"))
         logging.resetLogging()
     logging.setupLogging(init.cfg)
+
+    # Any log usage prior to setupLogging above did not have local user log
+    # config applied.  We send the welcome message now, as stderr/out have
+    # been redirected and log now configured.
+    welcome(name, msg=w_msg)
+
     # Stage 3
     try:
         init.initialize()
@@ -284,7 +296,7 @@ def main_modules(action_name, args):
     #    the modules objects configuration
     # 5. Run the modules for the given stage name
     # 6. Done!
-    welcome("%s:%s" % (action_name, name))
+    w_msg = welcome_format("%s:%s" % (action_name, name))
     init = stages.Init(ds_deps=[])
     # Stage 1
     init.read_cfg(extract_fns(args))
@@ -316,6 +328,10 @@ def main_modules(action_name, args):
                     " longer be active shortly"))
         logging.resetLogging()
     logging.setupLogging(mods.cfg)
+
+    # now that logging is setup and stdout redirected, send welcome
+    welcome(name, msg=w_msg)
+
     # Stage 5
     return run_module_section(mods, name, name)
 
@@ -335,7 +351,7 @@ def main_single(name, args):
     # 5. Run the single module
     # 6. Done!
     mod_name = args.name
-    welcome("%s:%s" % (name, mod_name))
+    w_msg = welcome_format(name)
     init = stages.Init(ds_deps=[])
     # Stage 1
     init.read_cfg(extract_fns(args))
@@ -374,6 +390,10 @@ def main_single(name, args):
                    " longer be active shortly"))
         logging.resetLogging()
     logging.setupLogging(mods.cfg)
+
+    # now that logging is setup and stdout redirected, send welcome
+    welcome(name, msg=w_msg)
+
     # Stage 5
     (which_ran, failures) = mods.run_single(mod_name,
                                             mod_args,

cloudinit/util.py

@@ -288,8 +288,10 @@ def multi_log(text, console=True, stderr=True,
             wfh.write(text)
             wfh.flush()
     if log:
-        log.log(log_level, text)
-
+        if text[-1] == "\n":
+            log.log(log_level, text[:-1])
+        else:
+            log.log(log_level, text)
 
 def is_ipv4(instr):
     """ determine if input string is a ipv4 address. return boolean"""