Strange NM 0.8.1 behaviour with static configuration

[Robert Vogelgesang <vogel users sourceforge net>]

Hello Dan and all,

maybe it's a little bit late to report a problem with 0.8.1, but anyway.

The system I'm experiencing this is a Mini-PC with a VIA Nehemiah 1GHz
processor, 500MB RAM, and three onboard RealTek RTL8139 network interfaces,
running Fedora 12 with all current updates, i. e. the installed NM RPMs
are:
NetworkManager-0.8.1-6.git20100831.fc12.i686
NetworkManager-glib-0.8.1-6.git20100831.fc12.i686
NetworkManager-gnome-0.8.1-6.git20100831.fc12.i686
NetworkManager-openvpn-0.8.1-0.1.git20100609.fc12.i686

On the first network interface, eth0, I configured a static setup back
then when installing Fedora 11, and kept it later when updating to
Fedora 12.  The other two network interfaces are not used and have
ONBOOT=no, and even NM_CONTROLLED=no in their ifcfg-ethN.  There are
two definitions of "alias addresses" for eth0, ifcfg-eth0:70 and
ifcfg-eth0:72; both have ONBOOT=no and ONPARENT=no.  These are used
on a case-by-case basis and started and stopped via scripts run by
root, when needed.

This worked like a charm until NetworkManager was updated to the first
0.8.1 "pre-release" some months ago.  I didn't notice the problem only
until some time later, because the misbehaviour of NetworkManager happens
only at boot, and this system normally gets rebooted only for kernel
updates.  And it required a few kernel updates to investigate the problem,
but now I'm pretty sure it's a NetworkManager misbehaviour, not the kernel.

The problem is that NetworkManager seems to ignore the ifcfg-eth0
completely on boot.  Instead, it first tried to set up an "Auto eth0"
using DHCP, until I put "no-auto-default=00:40:f4:b8:91:be" into
/etc/NetworkManager/NetworkManager.conf.  Since then, the NM Gnome
applet only shows a disabled "Auto eth0" after loggin in.  But when
I open a terminal window, "su" to root, edit the ifcfg-eth0, and
change for example the order of the last two lines, and save the file,
then NetworkManager reads the ifcfg-eth0 and starts the setup as
configured.  The Gnome applet now shows "System eth0" instead of the
"Auto eth0".  After the next reboot the same happens, i. e. I change
the the order of the last two lines of ifcfg-eth0 back and forth, but
"System eth0" never gets started immediately after boot, as it should.

Some log excerpts from the last boot:

Sep 26 23:51:49 argon kernel: Initalizing network drop monitor service
Sep 26 23:51:52 argon avahi-daemon[820]: Network interface enumeration completed.
Sep 26 23:52:03 argon NetworkManager[1052]: <info> NetworkManager (version 0.8.1-6.git20100831.fc12) is starting...
Sep 26 23:52:03 argon NetworkManager[1052]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
Sep 26 23:52:04 argon NetworkManager[1052]: <info> VPN: loaded org.freedesktop.NetworkManager.openvpn
Sep 26 23:52:04 argon NetworkManager[1052]: <info> trying to start the modem manager...
Sep 26 23:52:04 argon NetworkManager[1052]: <info> monitoring kernel firmware directory '/lib/firmware'.
Sep 26 23:52:04 argon NetworkManager[1052]:    ifcfg-rh: Acquired D-Bus service com.redhat.ifcfgrh1
Sep 26 23:52:04 argon NetworkManager[1052]: <info> Loaded plugin ifcfg-rh: (c) 2007 - 2008 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Sep 26 23:52:04 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... 
Sep 26 23:52:04 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth2 ... 
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth2'
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: Ignoring connection 'System eth2' and its device due to NM_CONTROLLED/BRIDGE/VLAN.
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth1 ... 
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth1'
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: Ignoring connection 'System eth1' and its device due to NM_CONTROLLED/BRIDGE/VLAN.
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ... 
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth0'
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0:72 ... 
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth0:72'
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0:70 ... 
Sep 26 23:52:05 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth0:70'
Sep 26 23:52:05 argon NetworkManager[1052]: <info> WiFi enabled by radio killswitch; enabled by state file
Sep 26 23:52:05 argon NetworkManager[1052]: <info> WWAN enabled by radio killswitch; enabled by state file
Sep 26 23:52:05 argon NetworkManager[1052]: <info> WiMAX enabled by radio killswitch; enabled by state file
Sep 26 23:52:05 argon NetworkManager[1052]: <info> Networking is enabled by state file
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): carrier is OFF
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): new Ethernet device (driver: '8139too' ifindex: 2)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): now managed
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): device state change: 1 -> 2 (reason 2)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): bringing up device.
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): preparing device.
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): deactivating device (reason: 2).
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth1): carrier is OFF
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth1): new Ethernet device (driver: '8139too' ifindex: 3)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/1
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth2): carrier is OFF
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth2): new Ethernet device (driver: '8139too' ifindex: 4)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth2): exported as /org/freedesktop/NetworkManager/Devices/2
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): carrier now ON (device state 2)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> (eth0): device state change: 2 -> 3 (reason 40)
Sep 26 23:52:05 argon NetworkManager[1052]: <info> modem-manager is now available
Sep 26 23:52:05 argon NetworkManager[1052]: <warn> bluez error getting default adapter: The name org.bluez was not provided by any .service files
Sep 26 23:52:05 argon NetworkManager[1052]: <info> Trying to start the supplicant...
Sep 26 23:53:05 argon NetworkManager[1052]: <error> [1285537985.370078] [nm-manager.c:1331] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Sep 26 23:53:05 argon NetworkManager[1052]: <error> [1285537985.772175] [nm-manager.c:1331] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name
Sep 26 23:53:05 argon NetworkManager[1052]: <error> [1285537985.782216] [nm-manager.c:1331] user_proxy_init(): could not init user settings proxy: (3) Could not get owner of name 'org.freedesktop.NetworkManagerUserSettings': no such name


At this point, no network interface is active.

After logging in, "su" to root in a xterm, and editing and saving ifcfg-eth0:

Sep 26 23:54:51 argon NetworkManager[1052]:    ifcfg-rh: removed /etc/sysconfig/network-scripts/ifcfg-eth0.
Sep 26 23:54:51 argon NetworkManager[1052]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ... 
Sep 26 23:54:51 argon NetworkManager[1052]:    ifcfg-rh:     read connection 'System eth0'
Sep 26 23:54:51 argon NetworkManager[1052]:    ifcfg-rh: updating /etc/sysconfig/network-scripts/ifcfg-eth0
Sep 26 23:54:51 argon NetworkManager[1052]:    ifcfg-rh: updating /etc/sysconfig/network-scripts/ifcfg-eth0
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) starting connection 'System eth0'
Sep 26 23:54:51 argon NetworkManager[1052]: <info> (eth0): device state change: 3 -> 4 (reason 0)
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> (eth0): device state change: 4 -> 5 (reason 0)
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> (eth0): device state change: 5 -> 7 (reason 0)
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) scheduled...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) started...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) complete.
Sep 26 23:54:51 argon NetworkManager[1052]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Sep 26 23:54:53 argon NetworkManager[1052]: <info> (eth0): device state change: 7 -> 8 (reason 0)
Sep 26 23:54:53 argon NetworkManager[1052]: <info> Policy set 'System eth0' (eth0) as default for IPv4 routing and DNS.
Sep 26 23:54:53 argon NetworkManager[1052]: <info> Activation (eth0) successful, device activated.
Sep 26 23:54:53 argon NetworkManager[1052]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.

After this, the setup works as expected.

The ifcfg-eth0:

# Networking Interface
DEVICE=eth0
BOOTPROTO=none
DNS1=192.168.1.1
GATEWAY=192.168.1.1
HWADDR=00:40:F4:B8:91:BE
IPADDR=192.168.1.11
NETMASK=255.255.255.0
ONBOOT=yes
NOZEROCONF=yes
TYPE=Ethernet
PREFIX=24
DEFROUTE=yes
NAME="System eth0"
UUID=5fb06bd0-0bb0-7ffb-45f1-d6edd65f3e03
DOMAIN=fritz.box
NM_CONTROLLED=yes
USERCTL=no
IPV6INIT=no


Please suggest what I should do if you need further information.

	Robert