[Pkg-utopia-maintainers] Bug#549332: network-manager: System lockup with NSS libc5 compat mode

Fri Oct 2 14:53:50 UTC 2009

Package: network-manager
Version: 0.6.6-3
Severity: important

Using libc5 compatible NIS authentication in combination with a DHCP
interface managed by NM leads to a kind of deadlock.

The default nsswitch.conf in Debian sets compat mode for passwd, group
and shadow. The Debian NIS Howto from the nis package then advocates 
adding "+" entries in /etc/passwd, /etc/group and /etc/shadow to enable
NIS authentication.

Once such modifications have been made, Network Manager fails to bring
up network connections. The path to failure goes as follows (excerpts from
syslog):

 0. dhcdb starts:

	15:55:59 dhcdbd: Started up.

 1. When taking charge of a new connection, NM first deactivates it:

	15:56:01 NetworkManager: <info>  New VPN service 'vpnc' (org.freedesktop.NetworkManager.vpnc).
	15:56:01 NetworkManager: <info>  eth0: Device is fully-supported using driver 'e1000e'.
	15:56:01 NetworkManager: <info>  nm_device_init(): waiting for device's worker thread to start
	15:56:01 NetworkManager: <info>  nm_device_init(): device's worker thread started, continuing.
	15:56:01 NetworkManager: <info>  Now managing wired Ethernet (802.3) device 'eth0'.
	15:56:01 NetworkManager: <info>  Deactivating device eth0.
	15:56:01 NetworkManager: <info>  Will activate wired connection 'eth0' because it now has a link.
	15:56:01 NetworkManager: <info>  SWITCH: no current connection, found better connection 'eth0'.

 2. Then dhcdb is lost:

	15:56:02 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.reason

 3. and NM learns about it, after a request times out:

	15:56:26 NetworkManager: <info>  Error from dhcdbd on 'reason' request because: name 'org.freedesktop.DBus.Error.NoReply', message 'Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.'.

 4. Then NM tries to get the interface up:

	15:56:26 NetworkManager: <info>  Will activate connection 'eth0'.
	15:56:26 NetworkManager: <info>  Device eth0 activation scheduled...
	15:56:26 NetworkManager: <info>  Activation (eth0) started...
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) successful.
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
	15:56:26 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
	15:56:27 NetworkManager: <info>  Activation (eth0) Beginning DHCP transaction.

 5. The DHCP transaction fails, seemingly because NM couldn't talk to DBUS:

	15:56:52 NetworkManager: <info>  Couldn't send DHCP 'up' message because: name 'org.freedesktop.DBus.Error.NoReply', message 'Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.'.

 6. hence the activation fails:

	15:56:52 NetworkManager: <info>  Activation (eth0) failure scheduled...
	15:56:52 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
	15:57:17 NetworkManager: <info>  Activation (eth0) failed.
	15:57:17 NetworkManager: <info>  Deactivating device eth0.
	15:57:17 NetworkManager: <info>  SWITCH: no current connection, found better connection 'eth0'.

 7. and we get back to step 2:

	15:57:42 NetworkManager: <info>  Error from dhcdbd on 'reason' request because: name 'org.freedesktop.DBus.Error.NoReply', message 'Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.'.

There are several fixes:

 - removing NM

 - adding a dummy option in /etc/interfaces to avoid NM managing the interface:

	auto eth0
	iface eth0 inet dhcp
		up /bin/true

 - avoiding compat mode by putting the following in nsswitch.conf:

	passwd:         files nis
	group:          files nis
	shadow:         files nis

We then obtain a clean boot sequence for NM:

	16:17:18 dhcdbd: Started up.
	16:17:20 NetworkManager: <info>  starting...
	16:17:20 NetworkManager: <info>  New VPN service 'vpnc' (org.freedesktop.NetworkManager.vpnc).
	16:17:20 NetworkManager: <info>  eth0: Device is fully-supported using driver 'e1000e'.
	16:17:20 NetworkManager: <info>  nm_device_init(): waiting for device's worker thread to start
	16:17:20 NetworkManager: <info>  nm_device_init(): device's worker thread started, continuing.
	16:17:20 NetworkManager: <info>  Now managing wired Ethernet (802.3) device 'eth0'.
	16:17:20 NetworkManager: <info>  Deactivating device eth0.
	16:17:20 NetworkManager: <info>  Will activate wired connection 'eth0' because it now has a link.
	16:17:20 NetworkManager: <info>  SWITCH: no current connection, found better connection 'eth0'.
	16:17:21 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.reason
	16:17:21 NetworkManager: <info>  Will activate connection 'eth0'.
	16:17:21 NetworkManager: <info>  Device eth0 activation scheduled...
	16:17:21 NetworkManager: <info>  Activation (eth0) started...
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) successful.
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
	16:17:21 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
	16:17:22 NetworkManager: <info>  Activation (eth0) Beginning DHCP transaction.
	16:17:22 NetworkManager: <info>  DHCP daemon state is now 12 (successfully started) for interface eth0
	16:17:22 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
	16:17:23 NetworkManager: <debug> [1254493043.221401] nm_hal_device_added(): New device added (hal udi is '/org/freedesktop/Hal/devices/pci_8086_29b2_drm_i915_card0').
	16:17:23 NetworkManager: <info>  DHCP daemon state is now 1 (starting) for interface eth0
	16:17:24 NetworkManager: <info>  DHCP daemon state is now 4 (reboot) for interface eth0
	16:17:24 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
	16:17:24 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
	16:17:24 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.domain_search
	16:17:24 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_domain
	16:17:24 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_servers
	16:17:24 NetworkManager: <info>  Retrieved the following IP4 configuration from the DHCP daemon:
	16:17:24 NetworkManager: <info>    address xxx.xxx.xxx.xxx
	16:17:24 NetworkManager: <info>    netmask 255.255.255.0
	16:17:24 NetworkManager: <info>    broadcast xxx.xxx.xxx.255
	16:17:24 NetworkManager: <info>    gateway xxx.xxx.xxx.1
	16:17:24 NetworkManager: <info>    nameserver xxx.xxx.xxx.xxx
	16:17:24 NetworkManager: <info>    hostname 'host'
	16:17:24 NetworkManager: <info>    domain name 'domain'
	16:17:24 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.interface_mtu
	16:17:24 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
	16:17:24 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
	16:17:24 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
	16:17:25 NetworkManager: <info>  DHCP returned name servers but system has disabled dynamic modification!
	16:17:25 NetworkManager: <info>  Activation (eth0) Finish handler scheduled.
	16:17:25 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
	16:17:25 NetworkManager: <info>  Activation (eth0) successful, device activated.

I'm not sure the bug is 100% NM related. Maybe NIS documentation should simply
be updated to advocate the modern NSS configuration. Or maybe this is a problem
with D-BUS security policy. Anyway, as it stands, NM is not compatible with the
default NIS client configuration.

This bug might also be related with bugs 500998 and 532670 about LDAP
authentication.

-- System Information:
Debian Release: 5.0.3
  APT prefers stable
  APT policy: (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 2.6.26-2-amd64 (SMP w/2 CPU cores)
Locale: LANG=fr_FR.UTF-8, LC_CTYPE=fr_FR.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash

Versions of packages network-manager depends on:
ii  adduser                   3.110          add and remove users and groups
ii  dbus                      1.2.1-5+lenny1 simple interprocess messaging syst
ii  dhcdbd                    3.0-5          D-Bus interface to the ISC DHCP cl
ii  hal                       0.5.11-8       Hardware Abstraction Layer
ii  ifupdown                  0.6.8+nmu1     high level tools to configure netw
ii  iproute                   20080725-2     networking and traffic control too
ii  libc6                     2.7-18         GNU C Library: Shared libraries
ii  libdbus-1-3               1.2.1-5+lenny1 simple interprocess messaging syst
ii  libdbus-glib-1-2          0.76-1         simple interprocess messaging syst
ii  libgcrypt11               1.4.1-1        LGPL Crypto library - runtime libr
ii  libglib2.0-0              2.16.6-2       The GLib library of C routines
ii  libgpg-error0             1.4-2          library for common error values an
ii  libhal1                   0.5.11-8       Hardware Abstraction Layer - share
ii  libiw29                   29-1.1         Wireless tools - library
ii  libnl1                    1.1-2          library for dealing with netlink s
ii  libnm-util0               0.6.6-3        network management framework (shar
ii  lsb-base                  3.2-20         Linux Standard Base 3.2 init scrip
ii  wpasupplicant             0.6.4-3        Client support for WPA and WPA2 (I

Versions of packages network-manager recommends:
ii  network-manager-gnome         0.6.6-4    network management framework (GNOM

network-manager suggests no packages.

-- no debconf information