Bug 1417025

Summary: cloud-init tries to run hostnamectl before dbus is up
Product: [Fedora] Fedora Reporter: Garrett Holmstrom <gholms>
Component: cloud-initAssignee: Garrett Holmstrom <gholms>
Status: CLOSED EOL QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 27CC: adimania, apevec, cwawak, gholms, Jan.van.Eldik, logan2211, shardy, s, wattersm
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-11-30 20:18:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Garrett Holmstrom 2017-01-27 02:40:37 UTC 
Description of problem:
=== From bug 1393094#c9 ===
I found an issue with the new cloud-init - basically during the run of cloud-init it tries to set the hostname using hostnamectl but dbus hasn't started yet and it fails. We need to figure this out. 

from the debug log: 

```
2017-01-25 08:59:38,338 - util.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3.5/site-packages/cloudinit/config/cc_set_hostname.py'>) failed
Traceback (most recent call last):
  File "/usr/lib/python3.5/site-packages/cloudinit/stages.py", line 776, in _run_modules
    freq=freq)
  File "/usr/lib/python3.5/site-packages/cloudinit/cloud.py", line 54, in run
    return self._runners.run(name, functor, args, freq, clear_on_fail)
  File "/usr/lib/python3.5/site-packages/cloudinit/helpers.py", line 187, in run
    results = functor(*args)
  File "/usr/lib/python3.5/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in handle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python3.5/site-packages/cloudinit/distros/__init__.py", line 84, in set_hostname
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python3.5/site-packages/cloudinit/distros/rhel.py", line 130, in _write_hostname
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python3.5/site-packages/cloudinit/util.py", line 1850, in subp
    cmd=args)
cloudinit.util.ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'cloudhost.localdomain']
Exit code: 1
Reason: -
Stdout: -
Stderr: Failed to create bus connection: No such file or directory

```

and from the journal you can see that dbus starts after cloud-init:

```
-bash-4.3# journalctl -u cloud-init | grep -P 'Starting|hostname' 
Jan 25 08:59:36 localhost.localdomain systemd[1]: Starting Initial cloud-init job (metadata service crawler)...
Jan 25 08:59:38 localhost.localdomain cloud-init[1308]: 2017-01-25 08:59:38,331 - util.py[WARNING]: Failed to set the hostname to cloudhost.localdomain (cloudhost)
Jan 25 08:59:38 localhost.localdomain cloud-init[1308]: 2017-01-25 08:59:38,338 - util.py[WARNING]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3.5/site-packages/cloudinit/config/cc_set_hostname.py'>) failed
-bash-4.3# 
-bash-4.3# 
-bash-4.3# journalctl -u dbus | head -n 2
-- Logs begin at Wed 2017-01-25 08:59:29 UTC, end at Wed 2017-01-25 09:02:04 UTC. --
Jan 25 08:59:38 localhost.localdomain systemd[1]: Started D-Bus System Message Bus.
```

We need to file a bug upstream and/or send a patch to get this fixed for us. 

I pulled the patch from the commit in the first comment of this BZ and applied it to cloud-init 0.7.8 in Fedora and built a scratch build:

https://koji.fedoraproject.org/koji/taskinfo?taskID=17405006


Version-Release number of selected component (if applicable):
cloud-init-0.7.9-1.fc26
Comment 1 Garrett Holmstrom 2017-01-27 03:04:33 UTC 
I added a potential fix to cloud-init-0.7.9-2.fc26 by removing DefaultDependencies=no from cloud-init.service.  Note that there is still discussion on this issue occurring upstream.
Comment 2 Fedora End Of Life 2017-02-28 11:06:34 UTC 
This bug appears to have been reported against 'rawhide' during the Fedora 26 development cycle.
Changing version to '26'.
Comment 3 Christopher Wawak 2017-11-14 21:42:52 UTC 
I'm still running into this on cloud-init-0.7.9-9.fc27.noarch:

[root@localhost log]# rpm -qv cloud-init
cloud-init-0.7.9-9.fc27.noarch

from /var/log/cloud-init.log
[...]
2017-11-14 16:34:34,265 - util.py[DEBUG]: Running module set_hostname (<module 'cloudinit.conf
ig.cc_set_hostname' from '/usr/lib/python3.6/site-packages/cloudinit/config/cc_set_hostname.py
'>) failed
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/cloudinit/stages.py", line 776, in _run_modules
    freq=freq)
  File "/usr/lib/python3.6/site-packages/cloudinit/cloud.py", line 54, in run
    return self._runners.run(name, functor, args, freq, clear_on_fail)
  File "/usr/lib/python3.6/site-packages/cloudinit/helpers.py", line 187, in run
    results = functor(*args)
  File "/usr/lib/python3.6/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in han
dle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python3.6/site-packages/cloudinit/distros/__init__.py", line 84, in set_hostn
ame
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python3.6/site-packages/cloudinit/distros/rhel.py", line 130, in _write_hostn
ame
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python3.6/site-packages/cloudinit/util.py", line 1850, in subp
    cmd=args)
cloudinit.util.ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'test2.home.wawak.org']
Exit code: 1
Reason: -
Stdout: -
Stderr: Failed to create bus connection: No such file or directory
Comment 4 Michael Watters 2017-11-20 15:34:16 UTC 
I'm seeing the same issue with ovirt nodes running CentOS 7.  The cloud-init logs show a bus connection error as shown below.

2017-11-20 10:20:54,076 - cc_set_hostname.py[DEBUG]: Setting the hostname to test.example.com (test)
2017-11-20 10:20:54,076 - util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'test.example.com'] with allowed return codes [0] (shell=False, capture=True)
2017-11-20 10:20:54,109 - util.py[WARNING]: Failed to set the hostname to test.example.com (test)
2017-11-20 10:20:54,109 - util.py[DEBUG]: Failed to set the hostname to test.example.com (test)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in handle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/__init__.py", line 84, in set_hostname
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/rhel.py", line 130, in _write_hostname
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python2.7/site-packages/cloudinit/util.py", line 1858, in subp
    cmd=args)
ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'test.example.com']
Exit code: 1
Reason: -
Stdout: -
Stderr: Failed to create bus connection: No such file or directory
Comment 5 Yaniv Kaul 2018-03-08 12:06:54 UTC 
Same here:
2018-03-08 10:54:02,733 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/b927f321-2ccb-4209-a512-286b06684d59/sem/config_set_hostname'>)
2018-03-08 10:54:02,733 - cc_set_hostname.py[DEBUG]: Setting the hostname to openshift-master-0.example.com (openshift-master-0)
2018-03-08 10:54:02,734 - util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'openshift-master-0.example.com'] with allowed return codes [0] (shell=False, capture=True)
2018-03-08 10:54:02,778 - util.py[WARNING]: Failed to set the hostname to openshift-master-0.example.com (openshift-master-0)
2018-03-08 10:54:02,779 - util.py[DEBUG]: Failed to set the hostname to openshift-master-0.example.com (openshift-master-0)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in handle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/__init__.py", line 84, in set_hostname
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/rhel.py", line 130, in _write_hostname
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python2.7/site-packages/cloudinit/util.py", line 1858, in subp
    cmd=args)
ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'openshift-master-0.example.com']
Exit code: 1
Reason: -
Stdout: -
Stderr: Failed to create bus connection: No such file or directory
2018-03-08 10:54:02,880 - handlers.py[DEBUG]: finish: init-local/config-set_hostname: FAIL: running config-set_hostname with frequency once-per-instance
2018-03-08 10:54:02,880 - util.py[WARNING]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.pyc'>) failed
2018-03-08 10:54:02,880 - util.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.pyc'>) failed
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cloudinit/stages.py", line 777, in _run_modules
    freq=freq)
  File "/usr/lib/python2.7/site-packages/cloudinit/cloud.py", line 54, in run
    return self._runners.run(name, functor, args, freq, clear_on_fail)
  File "/usr/lib/python2.7/site-packages/cloudinit/helpers.py", line 187, in run
    results = functor(*args)
  File "/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in handle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/__init__.py", line 84, in set_hostname
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python2.7/site-packages/cloudinit/distros/rhel.py", line 130, in _write_hostname
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python2.7/site-packages/cloudinit/util.py", line 1858, in subp
    cmd=args)
ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'openshift-master-0.example.com']
Exit code: 1
Reason: -
Stdout: -


[root@localhost ~]# rpm -qa |grep cloud
cloud-utils-growpart-0.29-2.el7.noarch
cloud-init-0.7.9-9.el7.centos.2.x86_64
[root@localhost ~]# cat /etc/redhat-release 
CentOS Linux release 7.4.1708 (Core)
Comment 6 Ben Cotton 2018-11-27 16:42:49 UTC 
This message is a reminder that Fedora 27 is nearing its end of life.
On 2018-Nov-30  Fedora will stop maintaining and issuing updates for
Fedora 27. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora  'version' of '27'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 27 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.
Comment 7 Ben Cotton 2018-11-30 20:18:05 UTC 
Fedora 27 changed to end-of-life (EOL) status on 2018-11-30. Fedora 27 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.
Comment 8 Logan V 2019-02-22 20:48:49 UTC 
I am seeing the same failure on Fedora 29.

2019-02-22 20:14:31,944 - cc_set_hostname.py[DEBUG]: Setting the hostname to wholedisk1 (wholedisk1)
2019-02-22 20:14:31,944 - util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'wholedisk1'] with allowed return codes [0] (shell=False, capture=True)
2019-02-22 20:14:31,955 - util.py[WARNING]: Failed to set the hostname to wholedisk1 (wholedisk1)
2019-02-22 20:14:31,955 - util.py[DEBUG]: Failed to set the hostname to wholedisk1 (wholedisk1)
Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/cloudinit/config/cc_set_hostname.py", line 47, in handle
    cloud.distro.set_hostname(hostname, fqdn)
  File "/usr/lib/python3.7/site-packages/cloudinit/distros/__init__.py", line 101, in set_hostname
    self._write_hostname(writeable_hostname, self.hostname_conf_fn)
  File "/usr/lib/python3.7/site-packages/cloudinit/distros/rhel.py", line 125, in _write_hostname
    util.subp(['hostnamectl', 'set-hostname', str(hostname)])
  File "/usr/lib/python3.7/site-packages/cloudinit/util.py", line 1847, in subp
    cmd=args)
cloudinit.util.ProcessExecutionError: Unexpected error while running command.
Command: ['hostnamectl', 'set-hostname', 'wholedisk1']
Exit code: 1
Reason: -
Stdout: -
Stderr: Failed to create bus connection: No such file or directory
2019-02-22 20:14:31,962 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: FAIL: running config-set_hostname with frequency once-per-instance