cloud-init-local.service messages not written to /var/log/cloud-init.log in systemd #2768

ubuntu-server-builder · 2023-05-10T19:03:16Z

This bug was originally filed in Launchpad as LP: #1643990

Launchpad details

affected_projects = ['cloud-init (Ubuntu)', 'cloud-init (Ubuntu Xenial)', 'cloud-init (Ubuntu Yakkety)']
assignee = None
assignee_name = None
date_closed = 2016-12-23T17:36:08.904691+00:00
date_created = 2016-11-22T19:23:07.279928+00:00
date_fix_committed = 2016-11-22T19:34:31.678634+00:00
date_fix_released = 2016-12-23T17:36:08.904691+00:00
id = 1643990
importance = medium
is_complete = True
lp_url = https://bugs.launchpad.net/cloud-init/+bug/1643990
milestone = None
owner = smoser
owner_name = Scott Moser
private = False
status = fix_released
submitter = smoser
submitter_name = Scott Moser
tags = ['verification-done']
duplicates = []

Launchpad user Scott Moser(smoser) wrote on 2016-11-22T19:23:07.279928+00:00

=== 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.

ubuntu-server-builder · 2023-05-10T19:03:18Z

Launchpad user Scott Moser(smoser) wrote on 2016-11-22T19:23:59.442250+00:00

I'm going to merge https://code.launchpad.net/~harlowja/cloud-init/+git/cloud-init/+merge/301729 to fix this bug.
That will mean that by default cloud-init.service does nto send output to rsyslog, but we'll get consistent timestamps in /var/log/cloud-init.log and also always get messages there.

ubuntu-server-builder · 2023-05-10T19:03:20Z

Launchpad user Scott Moser(smoser) wrote on 2016-12-23T17:36:07.759150+00:00

This is fixed in cloud-init 0.7.9.

ubuntu-server-builder · 2023-05-10T19:03:22Z

Launchpad user Brian Murray(brian-murray) wrote on 2017-01-12T19:48:07.236423+00:00

Hello Scott, or anyone else affected,

Accepted cloud-init into yakkety-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/cloud-init/0.7.8-68-gca3ae67-0ubuntu1~16.10.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

ubuntu-server-builder · 2023-05-10T19:03:24Z

Launchpad user Scott Moser(smoser) wrote on 2017-01-20T15:24:01.974344+00:00

$ lxc launch ubuntu-daily:yakkety y1
$ sleep 10
$ lxc exec y1 /bin/bash

% head -n 1 /var/log/cloud-init.log
Jan 20 15:17:35 y1 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.8 running 'modules:config' at Fri, 20 Jan 2017 15:17:34 +0000. Up 11.0 seconds.

% dpkg-query --show cloud-init
cloud-init 0.7.8-49-g9e904bb-0ubuntu1~16.10.1

% cat /etc/cloud/build.info
build_name: server
serial: 20170114

% m=http://archive.ubuntu.com/ubuntu
% echo "deb $m $(lsb_release -sc)-proposed main" > /etc/apt/sources.list.d/proposed.list

% apt update -q
% apt install cloud-init
% dpkg-query --show cloud-init
cloud-init 0.7.8-68-gca3ae67-0ubuntu1~16.10.1

keep seed dir for lxd datasource

% ( cd /var/lib/cloud && for d in ; do [ "$d" = "seed" ] && continue; rm -Rf "$d"; done )
% rm -Rf /var/log/cloud

% reboot

$ lxc exec y1 /bin/bash
% head -n 1 /var/log/cloud-init.log
2017-01-20 15:23:16,213 - util.py[DEBUG]: Cloud-init v. 0.7.8 running 'init-local' at Fri, 20 Jan 2017 15:23:16 +0000. Up 1.0 seconds.

ubuntu-server-builder · 2023-05-10T19:03:26Z

Launchpad user Andy Whitcroft(apw) wrote on 2017-01-30T18:17:46.933368+00:00

The verification of the Stable Release Update for cloud-init has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

ubuntu-server-builder · 2023-05-10T19:03:28Z

Launchpad user Launchpad Janitor(janitor) wrote on 2017-01-30T18:18:12.820305+00:00

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@ubuntu.com Mon, 19 Dec 2016 15:07:12 -0500

ubuntu-server-builder · 2023-05-10T19:03:30Z

Launchpad user Brian Murray(brian-murray) wrote on 2017-02-06T15:44:25.325062+00:00

Hello Scott, or anyone else affected,

Accepted cloud-init into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/cloud-init/0.7.9-0ubuntu1~16.04.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

ubuntu-server-builder · 2023-05-10T19:03:32Z

Launchpad user Brian Murray(brian-murray) wrote on 2017-02-06T21:33:22.397811+00:00

Hello Scott, or anyone else affected,

Accepted cloud-init into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/cloud-init/0.7.9-0ubuntu1~16.04.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

ubuntu-server-builder · 2023-05-10T19:03:34Z

Launchpad user Scott Moser(smoser) wrote on 2017-02-09T02:30:01.949763+00:00

$ release=xenial
$ lxc launch ubuntu-daily:$release $name

$ lxc exec $name -- dpkg-query --show cloud-init
cloud-init 0.7.8-49-g9e904bb-0ubuntu1~16.04.4

$ lxc file pull $name/etc/cloud/build.info -
build_name: server
serial: 20170207

$ lxc exec $name -- head -n 1 /var/log/cloud-init.log
Feb 9 02:26:04 x1 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.8 running 'modules:config' at Thu, 09 Feb 2017 02:26:03 +0000. Up 9.0 seconds.

enable proposed, update

$ m=http://archive.ubuntu.com/ubuntu;
$ echo "deb $m $release-proposed main" | lxc file push - $name/etc/apt/sources.list.d/proposed.list
$ lxc exec $name -- sh -c 'apt-get update -q && apt-get install cloud-init' </dev/null
$ lxc exec $name -- dpkg-query --show cloud-init
cloud-init 0.7.9-0ubuntu1~16.04.2

clean up to make it look like first boot.

$ lxc exec $name -- sh -c 'cd /var/lib/cloud; for d in ; do [ "$d" = "seed" ] || rm -vRf "$d"; done'
$ lxc exec $name -- sh -c 'rm -f /var/log/cloud'
$ lxc restart $name

$ lxc exec $name -- grep WARN /var/log/cloud-init.log || echo no warn
no warn
$ lxc exec $name -- head -n 1 /var/log/cloud-init.log
2017-02-09 02:29:15,960 - util.py[DEBUG]: Cloud-init v. 0.7.9 running 'init-local' at Thu, 09 Feb 2017 02:29:15 +0000. Up 1.0 seconds.

ubuntu-server-builder · 2023-05-10T19:03:36Z

Launchpad user Launchpad Janitor(janitor) wrote on 2017-02-22T00:43:01.813488+00:00

This bug was fixed in the package cloud-init - 0.7.9-0ubuntu1~16.04.2

cloud-init (0.7.9-0ubuntu1~16.04.2) xenial-proposed; urgency=medium

debian/update-grub-legacy-ec2: fix shell syntax error. (LP: #1662221)

cloud-init (0.7.9-0ubuntu1~16.04.1) xenial-proposed; urgency=medium

debian/copyright: update License field to include Apache.
debian/update-grub-legacy-ec2: fix to include kernels whose config
has CONFIG_XEN=y (LP: #1379080).
debian/patches/azure-use-walinux-agent.patch: continue relying on
walinux agent in stable release.
New upstream release.
- doc: adjust headers in tests documentation for consistency.
- pep8: fix issue found in zesty build with pycodestyle.
- integration test: initial commit of integration test framework
  [Wesley Wiedenmeier]
- LICENSE: Allow dual licensing GPL-3 or Apache 2.0 [Jon Grimm]
- Fix config order of precedence, putting kernel command line over system.
  [Wesley Wiedenmeier] (LP: #1582323)
- pep8: whitespace fix [Scott Moser]
- Update the list of valid ssh keys. [Michael Felt]
- network: add ENI unit test for statically rendered routes.
- set_hostname: avoid erroneously appending domain to fqdn
  [Lars Kellogg-Stedman] (LP: #1647910)
- doc: change 'nobootwait' to 'nofail' in docs [Anhad Jai Singh]
- Replace an expired bit.ly link in code comment. [Joshua Harlow]
- user-groups: fix bug when groups was provided as string and had spaces
  [Scott Moser] (LP: #1354694)
- 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
  [Joshua Harlow] (LP: #1625766)
- fix problems found in python2.6 test. [Joshua Harlow]
- 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]

-- Scott Moser smoser@ubuntu.com Mon, 06 Feb 2017 16:18:28 -0500

ubuntu-server-builder added the launchpad Migrated from Launchpad label May 10, 2023

ubuntu-server-builder closed this as completed May 10, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

cloud-init-local.service messages not written to /var/log/cloud-init.log in systemd #2768

cloud-init-local.service messages not written to /var/log/cloud-init.log in systemd #2768

ubuntu-server-builder commented May 10, 2023

grep Cloud-init /var/log/cloud-init.log

enable propose and update

cleanup

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

cloud-init-local.service messages not written to /var/log/cloud-init.log in systemd #2768

cloud-init-local.service messages not written to /var/log/cloud-init.log in systemd #2768

Comments

ubuntu-server-builder commented May 10, 2023

grep Cloud-init /var/log/cloud-init.log

enable propose and update

cleanup

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

keep seed dir for lxd datasource

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

ubuntu-server-builder commented May 10, 2023

enable proposed, update

clean up to make it look like first boot.

ubuntu-server-builder commented May 10, 2023