[Bug 1563590] Re: 1.25.4, xenial, init script install error race

Mon Apr 11 15:45:28 UTC 2016

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

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1563590

Title:
  1.25.4, xenial, init script install error race

Status in juju-core:
  New
Status in systemd package in Ubuntu:
  In Progress

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'>)

To manage notifications about this bug go to:
https://bugs.launchpad.net/juju-core/+bug/1563590/+subscriptions