yahoo-eng-team team mailing list archive

[Launchpad Bug Tracker <1643990@xxxxxxxxxxxxxxxxxx>]

This bug was fixed in the package cloud-init -
0.7.8-68-gca3ae67-0ubuntu1~16.10.1

---------------
cloud-init (0.7.8-68-gca3ae67-0ubuntu1~16.10.1) yakkety; urgency=medium

  * debian/cherry-pick: add utility for cherry picking commits from upstream
    into patches in debian/patches.
  * New upstream snapshot.
    - mounts: use mount -a again to accomplish mounts (LP: #1647708)
    - CloudSigma: Fix bug where datasource was not loaded in local search.
      (LP: #1648380)
    - when adding a user, strip whitespace from group list
      [Lars Kellogg-Stedman] (LP: #1354694)
    - fix decoding of utf-8 chars in yaml test
    - Replace usage of sys_netdev_info with read_sys_net (LP: #1625766)
    - fix problems found in python2.6 test.
    - OpenStack: extend physical types to include hyperv, hw_veb, vhost_user.
      (LP: #1642679)
    - tests: fix assumptions that expected no eth0 in system. (LP: #1644043)
    - net/cmdline: Consider ip= or ip6= on command line not only ip=
      (LP: #1639930)
    - Just use file logging by default [Joshua Harlow] (LP: #1643990)
    - Improve formatting for ProcessExecutionError [Wesley Wiedenmeier]
    - flake8: fix trailing white space
    - Doc: various documentation fixes [Sean Bright]
    - cloudinit/config/cc_rh_subscription.py: Remove repos before adding
      [Brent Baude]
    - packages/redhat: fix rpm spec file.
    - main: set TZ in environment if not already set. [Ryan Harper]
    - disk_setup: Use sectors as unit when formatting MBR disks with sfdisk.
      [Daniel Watkins] (LP: #1460715)

 -- Scott Moser <smoser@xxxxxxxxxx>  Mon, 19 Dec 2016 15:07:12 -0500

** Changed in: cloud-init (Ubuntu Yakkety)
       Status: Fix Committed => Fix Released

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to cloud-init.
https://bugs.launchpad.net/bugs/1643990

Title:
  cloud-init-local.service messages not written to /var/log/cloud-
  init.log in systemd

Status in cloud-init:
  Fix Released
Status in cloud-init package in Ubuntu:
  Fix Released
Status in cloud-init source package in Xenial:
  Triaged
Status in cloud-init source package in Yakkety:
  Fix Released

Bug description:
  === Begin SRU Template ===
  [Impact] 
  Cloud-init's logging is inconsistent due to availability of syslog during
  boot.

  Cloud-init logs to /var/log/cloud-init.log by default.  It does this in
  a way that was originally designed to prefer to use syslog if it was
  available, and then fall back to writing directly to that file.

  Over time this has been shown to be problematic.
  a.) it relied on syslog during boot, and on some distros it wasn't
      present.
  b.) sometimes it would not be available during cloud-init-local.service
      and then would be during cloud-init.service.  The result was that
      the log would have two different time stamp formats (one written
      by rsyslog and one by python logging).
  c.) if rsyslog was used, micro seconds were not included in the log.
  d.) since the move to systemd, there has even been times when cloud-init's
      attempt to determine if syslog was available would false-positive.
      that would result logging not being written to the file at all.

  Over all, the complexity was just not found to worth the benefit.

  [Test Case]
    * Launch an instance.
    * Look at /var/log/cloud-init.log.
      on start, the cloud-int process logs a message like
        'Cloud-init v 0.7.8 running'
      Look at those messages specifically.  In the example here (lxd), neither
      cloud-init.service or cloud-init-local.service successfully logged at all.

      # grep Cloud-init /var/log/cloud-init.log 
      Dec  2 18:06:56 y2 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.8 running 'modules:config' at Fri, 02 Dec 2016 18:06:56 +0000. Up 5.0 seconds.
      Dec  2 18:06:58 y2 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.8 running 'modules:final' at Fri, 02 Dec 2016 18:06:58 +0000. Up 7.0 seconds.
      Dec  2 18:06:58 y2 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.8 finished at Fri, 02 Dec 2016 18:06:58 +0000. Datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net].  Up 7.0 seconds

    * update to proposed, cleanup reboot
      # enable propose and update
      # cleanup

      sudo rm -Rf /var/log/cloud-init* /var/lib/cloud/
      sudo reboot
      
    * login again and look.

      This time, all messages will have the format:
         2016-12-02 17:58:43,175 - util.py[DEBUG]: Cloud-init v. 0.7.8 running 'init-local' at Fri, 02 Dec 2016 17:58:43 +0000. Up 13.73 seconds.

      And you will have one for each 'init-local', 'init', 'modules:config' and
      modules:final.

  [Regression Potential] 
  Users relying on cloud-init writing entries to syslog will lose that.

  [Other Info]

  === End SRU Template ===

  
  output of cloud-init-local.service can get lost in systemd.
  The result is that there is no output in /var/log/cloud-init.log from cloud-init-local.service.

  There is some information in https://code.launchpad.net/~harlowja/cloud-init/+git/cloud-init/+merge/301729
  about how this occurrs and how it used to work.
  copying part of that here:

  Cloud-init's logging basically employed a "try syslog and fallback to direct log to file".
  The proposed "just log to a file" is definitely dramatically simpler and advantageous in some cases.

  The way the "try syslog and fallback" works (or worked) on Ubuntu up
  until systemd was:

  a.) cloud-init init --local
      1. read logging config,
      2. attempt to log to syslog ([ *log_base, *log_syslog ])
      3. that fail, so it log to file directly

  b.) cloud-init init
     1.) rsyslog would have /dev/log up functional at this point
     2.) cloud-init logging config read and ends up logging to syslog

  Systemd changed some things in teh way /dev/log was handled, and the
  above no longer worked well.

  Additionally, cloud-init installs a file
  /etc/rsyslog.d/21-cloudinit.conf which tells rsyslog to redirect
  messages generated by cloud-init to /var/log/cloud-init.log

  The value of doing this in this way was that we use syslog, so if the
  user had configured the system to log remotely, cloud-init's logs
  would go to that remote system as they desired.

  If we directly log to a file, then cloud-init's log messages will not
  without further configuration go to syslog.

  One other thing to be aware of is that cloud-init can itself configure
  rsyslog through cloudinit/config/cc_rsyslog.py . So, the user could
  provide in user-data some rsyslog configuration, and then the system's
  syslog (including cloud-init messages) would start goign to that
  remote server as soon as they realistically could.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cloud-init/+bug/1643990/+subscriptions