1.25.4, xenial, init script install error race

Bug #1563590 reported by David Britton
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
juju-core
Invalid
Undecided
Unassigned
systemd (Ubuntu)
Fix Released
Low
Martin Pitt

Bug Description

Notice the error: "The unit files have no [Install] section. They are not meant to be enabled using systemctl." And the long error message after it saying this could be for a number of reasons. My only clue is perhaps some kind of race, since I get this only occasionally.

Here is the contents of the systemd file:

/etc/systemd/system/multi-user.target.wants/jujud-machine-1.service

http://paste.ubuntu.com/15555673/

Note, it does have an [Install] section, so I think the error from systemd link is at best misleading.

Mar 29 21:47:37 pascal cloud-init[4957]: + mkdir -p /var/lib/juju/tools/1.25.4-xenial-amd64
Mar 29 21:47:37 pascal cloud-init[4957]: + echo Fetching tools: curl -sSfw 'tools from %{url_effective} downloaded: HTTP %{http_code}; time %{time_total}s; size %{size_download} bytes; speed %{speed_download} bytes/s ' --noproxy "*" --insecure -o $bin/tools.tar.gz <[
Mar 29 21:47:37 pascal cloud-init[4957]: Fetching tools: curl -sSfw 'tools from %{url_effective} downloaded: HTTP %{http_code}; time %{time_total}s; size %{size_download} bytes; speed %{speed_download} bytes/s ' --noproxy "*" --insecure -o $bin/tools.tar.gz <[https:/
Mar 29 21:47:37 pascal cloud-init[4957]: + seq 5
Mar 29 21:47:37 pascal cloud-init[4957]: + printf Attempt 1 to download tools from %s...\n https://10.1.101.81:17070/tools/1.25.4-xenial-amd64
Mar 29 21:47:37 pascal cloud-init[4957]: Attempt 1 to download tools from https://10.1.101.81:17070/tools/1.25.4-xenial-amd64...
Mar 29 21:47:37 pascal cloud-init[4957]: + curl -sSfw tools from %{url_effective} downloaded: HTTP %{http_code}; time %{time_total}s; size %{size_download} bytes; speed %{speed_download} bytes/s --noproxy * --insecure -o /var/lib/juju/tools/1.25.4-xenial-amd64/tools
Mar 29 21:47:39 pascal cloud-init[4957]: tools from https://10.1.101.81:17070/tools/1.25.4-xenial-amd64 downloaded: HTTP 200; time 2.408s; size 16602428 bytes; speed 6893479.000 bytes/s + echo Tools downloaded successfully.
Mar 29 21:47:39 pascal cloud-init[4957]: Tools downloaded successfully.
Mar 29 21:47:39 pascal cloud-init[4957]: + break
Mar 29 21:47:39 pascal cloud-init[4957]: + sha256sum /var/lib/juju/tools/1.25.4-xenial-amd64/tools.tar.gz
Mar 29 21:47:40 pascal cloud-init[4957]: + grep 416c01467ac9ddd17907d3ab627631df10822c2a706631b86efead6f3f38d27b /var/lib/juju/tools/1.25.4-xenial-amd64/juju1.25.4-xenial-amd64.sha256
Mar 29 21:47:40 pascal cloud-init[4957]: 416c01467ac9ddd17907d3ab627631df10822c2a706631b86efead6f3f38d27b /var/lib/juju/tools/1.25.4-xenial-amd64/tools.tar.gz
Mar 29 21:47:40 pascal cloud-init[4957]: + tar zxf /var/lib/juju/tools/1.25.4-xenial-amd64/tools.tar.gz -C /var/lib/juju/tools/1.25.4-xenial-amd64
Mar 29 21:47:40 pascal cloud-init[4957]: + printf %s {"version":"1.25.4-xenial-amd64","url":"https://10.1.101.81:17070/environment/94a7eb52-f85f-4280-8b51-0f9c8cc07748/tools/1.25.4-xenial-amd64","sha256":"416c01467ac9ddd17907d3ab627631df10822c2a706631b86efead6f3f38d2
Mar 29 21:47:40 pascal cloud-init[4957]: + mkdir -p /var/lib/juju/agents/machine-1
Mar 29 21:47:40 pascal cloud-init[4957]: + cat
Mar 29 21:47:40 pascal cloud-init[4957]: + chmod 0600 /var/lib/juju/agents/machine-1/agent.conf
Mar 29 21:47:40 pascal cloud-init[4957]: + ln -s 1.25.4-xenial-amd64 /var/lib/juju/tools/machine-1
Mar 29 21:47:40 pascal cloud-init[4957]: + echo Starting Juju machine agent (jujud-machine-1)
Mar 29 21:47:40 pascal cloud-init[4957]: Starting Juju machine agent (jujud-machine-1)
Mar 29 21:47:40 pascal cloud-init[4957]: + mkdir -p /var/lib/juju/init/jujud-machine-1
Mar 29 21:47:40 pascal cloud-init[4957]: + cat
Mar 29 21:47:40 pascal cloud-init[4957]: + chmod 0755 /var/lib/juju/init/jujud-machine-1/exec-start.sh
Mar 29 21:47:40 pascal cloud-init[4957]: + cat
Mar 29 21:47:40 pascal cloud-init[4957]: + /bin/systemctl link /var/lib/juju/init/jujud-machine-1/jujud-machine-1.service
Mar 29 21:47:40 pascal cloud-init[4957]: Created symlink from /etc/systemd/system/jujud-machine-1.service to /var/lib/juju/init/jujud-machine-1/jujud-machine-1.service.
Mar 29 21:47:40 pascal systemd[1]: Reloading.
Mar 29 21:47:40 pascal systemd[1]: Started ACPI event daemon.
Mar 29 21:47:40 pascal cloud-init[4957]: + /bin/systemctl daemon-reload
Mar 29 21:47:40 pascal systemd[1]: Reloading.
Mar 29 21:47:40 pascal systemd[1]: Started ACPI event daemon.
Mar 29 21:47:40 pascal cloud-init[4957]: + /bin/systemctl enable /var/lib/juju/init/jujud-machine-1/jujud-machine-1.service
Mar 29 21:47:40 pascal cloud-init[4957]: Created symlink from /etc/systemd/system/multi-user.target.wants/jujud-machine-1.service to /var/lib/juju/init/jujud-machine-1/jujud-machine-1.service.
Mar 29 21:47:40 pascal kernel: ax88179_178a 2-1.6:1.0 eth1: ax88179 - Link status is: 1
Mar 29 21:47:40 pascal systemd[1]: Reloading.
Mar 29 21:47:40 pascal kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Mar 29 21:47:40 pascal cloud-init[4957]: The unit files have no [Install] section. They are not meant to be enabled
Mar 29 21:47:40 pascal cloud-init[4957]: using systemctl.
Mar 29 21:47:40 pascal cloud-init[4957]: Possible reasons for having this kind of units are:
Mar 29 21:47:40 pascal cloud-init[4957]: 1) A unit may be statically enabled by being symlinked from another unit's
Mar 29 21:47:40 pascal cloud-init[4957]: .wants/ or .requires/ directory.
Mar 29 21:47:40 pascal cloud-init[4957]: 2) A unit's purpose may be to act as a helper for some other unit which has
Mar 29 21:47:40 pascal cloud-init[4957]: a requirement dependency on it.
Mar 29 21:47:40 pascal cloud-init[4957]: 3) A unit may be started when needed via activation (socket, path, timer,
Mar 29 21:47:40 pascal cloud-init[4957]: D-Bus, udev, scripted systemctl call, ...).
Mar 29 21:47:40 pascal cloud-init[4957]: + /bin/systemctl start jujud-machine-1.service
Mar 29 21:47:40 pascal systemd[1]: Started ACPI event daemon.
Mar 29 21:47:40 pascal systemd[1]: Started juju agent for machine-1.
Mar 29 21:47:40 pascal cloud-init[4957]: + rm /var/lib/juju/tools/1.25.4-xenial-amd64/tools.tar.gz
Mar 29 21:47:40 pascal cloud-init[4957]: + rm /var/lib/juju/tools/1.25.4-xenial-amd64/juju1.25.4-xenial-amd64.sha256
Mar 29 21:47:40 pascal cloud-init[4957]: + rm -f /tmp/add-juju-bridge.py
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://10.0.7.8/MAAS/metadata/status/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca' with {'allow_redirects': True, 'headers': {'Authorization': 'OAuth oauth_nonce="78117408733297676101
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://10.0.7.8/MAAS/metadata/status/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca (200, 2b) after 1 attempts
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequen
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
Mar 29 21:47:40 pascal cloud-init[4957]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://10.0.7.8/MAAS/metadata/status/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca' with {'allow_redirects': True, 'headers': {'Authorization': 'OAuth oauth_nonce="47085513177405626714
Mar 29 21:47:41 pascal cloud-init[4957]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://10.0.7.8/MAAS/metadata/status/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca (200, 2b) after 1 attempts
Mar 29 21:47:41 pascal cloud-init[4957]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca/sem/config_ssh_authkey_fingerprints - wb: [420] 25 bytes
Mar 29 21:47:41 pascal cloud-init[4957]: [CLOUDINIT] helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/node-093f8460-a678-11e4-a5bf-a0b3cce4ecca/sem/config_ssh_authkey_fingerprints'>)

Tags: landscape
tags: added: kanban-cross-team
tags: removed: kanban-cross-team
Revision history for this message
Cheryl Jennings (cherylj) wrote :

Ha, in trying to get a clean run on juju 2.0 with lxd provider for comparison, I just hit this issue as well. I'll need to collect a pass / fail clout-init-output.log for comparison and tap pitti for some guidance on where to start.

David - are you using "released" or "daily" images for xenial? In my case, I hit this using a "released" image.

Revision history for this message
David Britton (dpb) wrote : Re: [Bug 1563590] Re: 1.25.4, xenial, init script install error race

there are "released" images? :)

I'm using daily I think.

On Thu, Apr 7, 2016 at 3:03 PM, Cheryl Jennings <
<email address hidden>> wrote:

> Ha, in trying to get a clean run on juju 2.0 with lxd provider for
> comparison, I just hit this issue as well. I'll need to collect a pass
> / fail clout-init-output.log for comparison and tap pitti for some
> guidance on where to start.
>
> David - are you using "released" or "daily" images for xenial? In my
> case, I hit this using a "released" image.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1563590
>
> Title:
> 1.25.4, xenial, init script install error race
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/juju-core/+bug/1563590/+subscriptions
>

--
David Britton <email address hidden>

Revision history for this message
Cheryl Jennings (cherylj) wrote :

'released' xenial images will get you beta2:

cat /etc/cloud/build.info
build_name: server
serial: 20160322-141433

'daily' will get you the latest.

cat /etc/cloud/build.info
build_name: server
serial: 20160406-141430

Revision history for this message
Cheryl Jennings (cherylj) wrote :

I now see this on all bootstraps on a xenial controller. Here's the files / commands we're using at bootstrap: http://paste.ubuntu.com/15753170/

Revision history for this message
Martin Pitt (pitti) wrote :

> /bin/systemctl link '/var/lib/juju/init/jujud-machine-0/jujud-machine-0.service'
> /bin/systemctl enable '/var/lib/juju/init/jujud-machine-0/jujud-machine-0.service'

This is redundant. Either use link like that and enable with just "jujud-machine-0.service" (link already created the symlink in the standard paths), or just directly enable the unit with full path and skip the link. However, this currently fails due to https://github.com/systemd/systemd/issues/3010, which is an actual regression.

Changed in systemd (Ubuntu):
status: New → In Progress
assignee: nobody → Martin Pitt (pitti)
Revision history for this message
Martin Pitt (pitti) wrote :

However, at least for me the enablement actually works, I do get both symlinks created. Just after that I get that (wrong) error message.

Revision history for this message
Martin Pitt (pitti) wrote :

Sorry, the first part of my advice in #5 was wrong. "systemctl enable foo.service" is not allowed if /etc/systemd/system/foo.service is a symlink (This currently causes the "too many levels of symbolic links" error, which is a crap message and we'll fix that).

So my revised advice is to just drop the redundant "systemctl link". "systemctl enable" on the full path will DTRT already; it currently works, but shows this bogus error message about "No [Install] section", which is mostly cosmetical (but I'll fix that too).

Revision history for this message
Martin Pitt (pitti) wrote :

Fix sent upstream in https://github.com/systemd/systemd/pull/3016 . This is only cosmetical, thus setting importance to "Low".

Changed in systemd (Ubuntu):
importance: Undecided → Low
Changed in juju-core:
status: New → Invalid
Martin Pitt (pitti)
Changed in systemd (Ubuntu):
status: In Progress → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package systemd - 229-4ubuntu4

---------------
systemd (229-4ubuntu4) xenial; urgency=medium

  * 73-special-net-names.rules: Further refine ibmveth naming.

 -- Martin Pitt <email address hidden> Tue, 12 Apr 2016 12:06:30 +0200

Changed in systemd (Ubuntu):
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.