Bug 1356015

This seems to be related to change in bug 1290858 - we stopped setting the static hostname of target system to hostname anaconda obtained from dhcp or dns lookup during installation when no --hostname was set by network kickstart command or in UI.

Now you need either to configure the hostname with kicstart network --hostname command or make sure the (transient) hostname of installed system is configured automatically by network configuration (ie by NM from dhcp or dns lookup) which should happen when static hostname is not set (or set to localhost.localdomain).

We have addressed similar issue reported from Beaker users related to change introduced by the change in the bug 1290858 by this patch:

https://github.com/rhinstaller/anaconda/commit/a53effe29597e5c6ee0423fe96e5ddd0b9c6e27f

The problem was that we set installed environment hostname to target system static hostname (localhost.localdomain) at the end of installation which made 
beaker kickstart script function function find_fqdn() fail to find fqdn of the system. This was fixed but it seems it is not the problem of your case (the target system static hostname (/etc/hostname) would still be set to localhost.localdomain if not configured otherwise).

I'd need to see anaconda logs to be sure, please attach them as individual text/plain attachments:

anaconda.log
syslog
program.log
ifcfg.log

You can find them on installed system in /var/log/anaconda
or in installer environment in /tmp. Or grab them from beaker job.

Also logs of NM on installed system can give hint why NM does not set expected hostname if it is supposed to do so.

Thank you for the logs. Unfortunately, logging of NM into sys.log is broken in current 7.3 builds (bug 1358335). The messages could be found in /var/log/anaconda/journal.log on installed system though - could you please try to obtain the log file (at the end of installation they can be found in /mnt/sysimage/var/log/anaconda/journal.log)? Or point me to some Beaker machine having the issue I could loan?

From kistkart %post script log it seems that installer gets the expected hostname during installation (set by NM configuration):

(Referring to https://beaker.engineering.redhat.com/jobs/1411278 logs)

<snip console.log>
Running post-installation scripts 
      
+ command -v curl
+ curl --help
+ grep -q '.*--retry'
++ find_fqdn
++ local fqdn=
+++ hostname -f
++ fqdn=hp-dl385pg8-07.rhts.eng.pek2.redhat.com
++ [[ hp-dl385pg8-07.rhts.eng.pek2.redhat.com == *.* ]]
++ [[ hp-dl385pg8-07.rhts.eng.pek2.redhat.com != localhost.* ]]
++ echo hp-dl385pg8-07.rhts.eng.pek2.redhat.com
++ return
+ REPORTED_FQDN=hp-dl385pg8-07.rhts.eng.pek2.redhat.com
</snip>

Unfortunately we don't have NM log messages from installer so we can't compare them from those from installed system where NM does not set the hostname upon activating eno1:

<snip messages>
Jul 21 08:28:33 localhost kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eno1: link becomes ready
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7858] device (eno1): link connected
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7864] policy: auto-activating connection 'eno1'
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7884] device (eno1): Activation: starting connection 'eno1' (507d3280-0ae6-4d2a-8bed-c8bfaaea8649)
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7886] device (eno1): state change: disconnected -> prepare (reason 'none') [30 40 0]
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7892] manager: NetworkManager state is now CONNECTING
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7905] device (eno1): state change: prepare -> config (reason 'none') [40 50 0]
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7921] device (eno1): state change: config -> ip-config (reason 'none') [50 70 0]
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.7935] dhcp4 (eno1): activation: beginning transaction (timeout in 45 seconds)
Jul 21 08:28:33 localhost NetworkManager[1149]: <info>  [1469104113.8935] dhcp4 (eno1): dhclient started with pid 1238
Jul 21 08:28:36 localhost dhclient[1238]: DHCPDISCOVER on eno1 to 255.255.255.255 port 67 interval 8 (xid=0x7e573ebb)
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8328] device (eno1): state change: ip-config -> ip-check (reason 'none') [70 80 0]
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8339] device (eno1): state change: ip-check -> secondaries (reason 'none') [80 90 0]
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8352] device (eno1): state change: secondaries -> activated (reason 'none') [90 100 0]
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8355] manager: NetworkManager state is now CONNECTED_LOCAL
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8366] manager: NetworkManager state is now CONNECTED_GLOBAL
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8368] policy: set 'eno1' (eno1) as default for IPv6 routing and DNS
Jul 21 08:28:39 localhost NetworkManager[1149]: <info>  [1469104119.8372] device (eno1): Activation: successful, device activated.
Jul 21 08:28:39 localhost nm-dispatcher: req:2 'up' [eno1]: new request (3 scripts)
Jul 21 08:28:39 localhost nm-dispatcher: req:2 'up' [eno1]: start running ordered scripts...
Jul 21 08:28:45 localhost dhclient[1238]: DHCPDISCOVER on eno1 to 255.255.255.255 port 67 interval 11 (xid=0x7e573ebb)
Jul 21 08:28:45 localhost dhclient[1238]: DHCPREQUEST on eno1 to 255.255.255.255 port 67 (xid=0x7e573ebb)
Jul 21 08:28:45 localhost dhclient[1238]: DHCPOFFER from 10.73.131.254
Jul 21 08:28:46 localhost dhclient[1238]: DHCPACK from 10.73.131.254 (xid=0x7e573ebb)
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1059]   address 10.73.130.77
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1059]   plen 23 (255.255.254.0)
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1060]   gateway 10.73.131.254
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1060]   server identifier 10.73.2.108
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1060]   lease time 43200
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1060]   hostname 'hp-dl385pg8-07.rhts.eng.pek2.redhat.com'
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1061]   nameserver '10.73.2.107'
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1061]   nameserver '10.73.2.108'
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1061]   nameserver '10.66.127.10'
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1061]   domain name 'rhts.eng.pek2.redhat.com'
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1062] dhcp4 (eno1): state changed unknown -> bound
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.1094] policy: set 'eno1' (eno1) as default for IPv4 routing and DNS
Jul 21 08:28:46 localhost dhclient[1238]: bound to 10.73.130.77 -- renewal in 16590 seconds.
Jul 21 08:28:46 localhost NetworkManager[1149]: <info>  [1469104126.2135] manager: startup complete
Jul 21 08:28:46 localhost nm-dispatcher: req:3 'dhcp4-change' [eno1]: new request (3 scripts)
Jul 21 08:28:46 localhost nm-dispatcher: req:3 'dhcp4-change' [eno1]: start running ordered scripts...
Jul 21 08:28:46 localhost systemd: Started Network Manager Wait Online.

</snip>

Please see the attachment 1182721 [details], I hope that will be helpful.

So reading the log from comment #9 the hostname was not set by NM (from dhcp) in installer either. It had already been set in initramfs stage of installation though (from dhcp), so find_fqdn() in kickstart %post works (returns the hp-dl385pg8-07.rhts.eng.pek2.redhat.com). On installed system initramfs does not configure networking so hostname is not set. We need to investigate why NM does not set the hostname. In my local tests I've also hit the issue of NM not setting the hostname (in installer environment in my case) in some of the installation instances but I am no more able to reproduce it. I have logs from one failing case though so I'll attach it and one for working instance as well.

Workaround for beaker would be to write fqdn obtained in %post installation kickstart by find_fqdn into /etc/hostname as static hostname (something that anaconda would effectively do before the change in bug 1290858).

Created attachment 1182845 [details]
NM not setting hostname from dhcp

Log of failing case mentioned in comment #11.

Created attachment 1182846 [details]
NM setting hostname from dhcp

Log of OK case mentioned in comment #11.

Jul 22 11:58:06 scratch2.anaconda.englab.brq.redhat.com NetworkManager[1260]: <info>  [1469188686.3301] policy: setting system hostname to 'scratch2' (from DHCPv4)

Created attachment 1182854 [details]
messages log from https://beaker.engineering.redhat.com/jobs/1411278

Attaching messages log from job so it doesn't get scratched.

Passing for debugging to NM.

The problem seem to be NM not setting hostname from dhcp in a beaker job. The NM logs should be in comment #14 (installed system) and comment #9 (installer).

It may be related to issue I describe in comment #11 where the hostname is sometimes set, sometimes not - logs (from installer) are in comment #12 and comment #13.

Created attachment 1183141 [details]
[PATCH] policy: update system hostname when DHCP configuration changes

Looks good.

Looks good to me too.

Patch applied to master:

https://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?id=9446481f4cc06c657d9467bce0921a85bb94ae6b

Created attachment 1188105 [details]
[PATCH] policy: fix hostname change when IP method ends after activation (take 2)

The previous patch didn't work in all cases, attached a new version.

*** Bug 1364393 has been marked as a duplicate of this bug. ***

Retested with scratch build from comment 22. Hostname is set correctly on our system and everything seems working fine. Thank you!

Notes for testing: the problem happened with a connection having ipv4.method=auto and ipv6.method=auto, when ipv6 configuration terminated before ipv4. To test this is sufficient to:

 - set 'localhost' hostname on client
 - start RA server
 - activate connection on client, which will succeed after getting the ipv6
   address
 - wait 10 seconds
 - start DHCPv4 server which provides a hostname

After DHCPv4 terminates, the hostname on client should be updated. If using isc-dhcp as DHCPv4 server, it is possible to set 'ping-check on' and 'ping-timeout 10' to delay the transaction completion.

Hi, with RHEL-7.2 and update of NM to NetworkManager-1:1.4.0-0.5.beta1.el7 I get following AVC denials:

type=SYSCALL msg=audit(1470839967.292:25): arch=c000003e syscall=2 success=no exit=-13 a0=7f3531581700 a1=c2 a2=1b6 a3=3 items=0 ppid=1 pid=1616 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="NetworkManager" exe="/usr/sbin/NetworkManager" subj=system_u:system_r:NetworkManager_t:s0 key=(null)
type=AVC msg=audit(1470839967.292:25): avc:  denied  { create } for  pid=1616 comm="NetworkManager" name="resolv.conf.JP54LY" scontext=system_u:system_r:NetworkManager_t:s0 tcontext=system_u:object_r:etc_t:s0 tclass=file

(In reply to Jan Tluka from comment #27)
> Hi, with RHEL-7.2 and update of NM to NetworkManager-1:1.4.0-0.5.beta1.el7 I
> get following AVC denials:
> 
> type=SYSCALL msg=audit(1470839967.292:25): arch=c000003e syscall=2
> success=no exit=-13 a0=7f3531581700 a1=c2 a2=1b6 a3=3 items=0 ppid=1
> pid=1616 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0
> fsgid=0 tty=(none) ses=4294967295 comm="NetworkManager"
> exe="/usr/sbin/NetworkManager" subj=system_u:system_r:NetworkManager_t:s0
> key=(null)
> type=AVC msg=audit(1470839967.292:25): avc:  denied  { create } for 
> pid=1616 comm="NetworkManager" name="resolv.conf.JP54LY"
> scontext=system_u:system_r:NetworkManager_t:s0
> tcontext=system_u:object_r:etc_t:s0 tclass=file

Hi, in RHEL 7.3 the SELinux policy has been updated to allow NetworkManager to write /etc/resolv.conf.XXXXXX files (see bug 1342401) so as long as the selinux-policy package is >= 3.13.1-80 the problem should go away.

We don't release NM 1.4 packages for RHEL 7.2, though, so that combination is untested. But if you really need to use it probably you should add a custom selinux policy.

(In reply to Beniamino Galvani from comment #28)
> (In reply to Jan Tluka from comment #27)
> > Hi, with RHEL-7.2 and update of NM to NetworkManager-1:1.4.0-0.5.beta1.el7 I
> > get following AVC denials:
> > 
> > type=SYSCALL msg=audit(1470839967.292:25): arch=c000003e syscall=2
> > success=no exit=-13 a0=7f3531581700 a1=c2 a2=1b6 a3=3 items=0 ppid=1
> > pid=1616 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0
> > fsgid=0 tty=(none) ses=4294967295 comm="NetworkManager"
> > exe="/usr/sbin/NetworkManager" subj=system_u:system_r:NetworkManager_t:s0
> > key=(null)
> > type=AVC msg=audit(1470839967.292:25): avc:  denied  { create } for 
> > pid=1616 comm="NetworkManager" name="resolv.conf.JP54LY"
> > scontext=system_u:system_r:NetworkManager_t:s0
> > tcontext=system_u:object_r:etc_t:s0 tclass=file
> 
> Hi, in RHEL 7.3 the SELinux policy has been updated to allow NetworkManager
> to write /etc/resolv.conf.XXXXXX files (see bug 1342401) so as long as the
> selinux-policy package is >= 3.13.1-80 the problem should go away.
> 
> We don't release NM 1.4 packages for RHEL 7.2, though, so that combination
> is untested. But if you really need to use it probably you should add a
> custom selinux policy.

Ok, with that explanation I'm fine. Thanks!

moving back to assigned as it's very likely not fixed properly

(In reply to Vladimir Benes from comment #31)
> moving back to assigned as it's very likely not fixed properly

Hi,

I think this is an issue not related with original one (missing
hostname at boot) and depends on the fact that the kernel hostname is
changed manually outside NM while NM is running. Most likely the same
problem existed in all previous versions of NM and I would say also
that its severity is low. What happens is that:

 - hostname is initially set to A
 - the user manually changes kernel hostname to B (but NM still
   considers A as hostname since it doesn't monitor kernel hostname
   changes)
 - a connection is brought up which pulls A as hostname
 - NM doesn't update the hostname as it thinks that A is already set

Created attachment 1191738 [details]
[PATCH] policy: always try to update kernel hostname

(In reply to Beniamino Galvani from comment #33)
> Created attachment 1191738 [details]
> [PATCH] policy: always try to update kernel hostname

lgtm

lgtm

Applied:

https://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?id=51b2cef04f7e929f012ae49a6c6d94e60bc68c16

https://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?h=nm-1-4&id=db14c1b167d9ff8f45a18a818a836f8f84e24037

Setting BZ to MODIFIED, as patches were merged; awaits next build.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2016-2581.html