NetworkManager with dhcpcd running and after having killed it(dhcpcd)

NetworkManagerDHCPrunning.log (text/plain), 8.99 KB, created by denysonique on 2010-08-19 05:47:41 UTC

This is a log of NetworkManager running in different scenarios

Version on NetworkManager installed on my system:
	net-misc/networkmanager-0.8.1-r3 (dhcpcd -dhclient) (other flags omitted)

DHCP client installed:
        net-misc/dhcpcd-5.2.7


STEP 1 - Freshly booted machine. 
	 Result: NetworkManager tries to aquire an IP address using
		/sbin/dhcpcd net-misc/dhcpcd (Roy Marples).
		It fails at doing this because /sbin/dhcpcd is already running.
		Which was previously started at boot time by /etc/init.d/dhcpcd



STEP 2 - After killing the /sbin/dhcpcd net-misc/dhcpcd (Roy Marples) process.
	 NetworkManager successfully has acquired the IP address using /sbin/dhcpcd.




SUMMARY
	NetworkManager tries to get the IP but it fails as /sbin/dhcpcd is already running(started at boot time by
	/etc/init.d/dhcpcd).
	After killing the dhcpcd process NetworkManager successfully connects using /etc/sbin/dhcpcd.



Below are the detailed logs of NetoworkManager.



STEP 1

I booted  my machine and stoped NetworkManager via /etc/init.d/NetworkManager stop and ran it using the /usr/bin/NetworkManager --no-daemon command
The /etc/init.d/dhcpcd is running (started at boot by /etc/init.d/dhcpcd)
ps output:
root      5083  0.0  0.0   2012   660 ?        Ss   04:38   0:00 /sbin/dhcpcd -q

output of NetworkManager while attempting to connect:

NetwrkManager[6192]: <info> Activation (wlan0) starting connection 'Auto badvista.org'
NetworkManager[6192]: <info> (wlan0): device state change: 3 -> 4 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[6192]: <info> (wlan0): device state change: 4 -> 5 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0/wireless): connection 'Auto badvista.org' requires no security.  No secrets needed.
NetworkManager[6192]: <info> Config: added 'ssid' value 'badvista.org'
NetworkManager[6192]: <info> Config: added 'scan_ssid' value '1'
NetworkManager[6192]: <info> Config: added 'key_mgmt' value 'NONE'
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[6192]: <info> Config: set interface ap_scan to 1
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  disconnected -> scanning
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  scanning -> associating
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  associating -> associated
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  associated -> completed
NetworkManager[6192]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'badvista.org'.
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[6192]: <info> (wlan0): device state change: 5 -> 7 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[6192]: nm_setting_ip4_config_get_dhcp_hostname: assertion `NM_IS_SETTING_IP4_CONFIG (setting)' failed
NetworkManager[6192]: <info> dhcpcd started with pid 6245
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
dhcpcd[6245]: sending commands to master dhcpcd process
NetworkManager[6192]: <info> (wlan0): DHCPv4 client pid 6245 exited with status 0
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) started...
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) complete.
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) failed (no IP configuration found)
NetworkManager[6192]: <info> (wlan0): device state change: 7 -> 9 (reason 5)
NetworkManager[6192]: <warn> Activation (wlan0) failed for access point (badvista.org)
NetworkManager[6192]: <info> Marking connection 'Auto badvista.org' invalid.
NetworkManager[6192]: <warn> Activation (wlan0) failed.
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
NetworkManager[6192]: <info> (wlan0): device state change: 9 -> 3 (reason 0)
NetworkManager[6192]: <info> (wlan0): deactivating device (reason: 0).







STEP 2

This is the output of /usr/sbin/NetworkManager --no-daemon when attempting to connect to a network after I have killed the dhcpcd process which was started by /etc/init.d/dhcpcd

I have successfully connected to the network:

NetworkManager[6192]: <info> Activation (wlan0) starting connection 'Auto badvista.org'
NetworkManager[6192]: <info> (wlan0): device state change: 3 -> 4 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[6192]: <info> (wlan0): device state change: 4 -> 5 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0/wireless): connection 'Auto badvista.org' requires no security.  No secrets needed.
NetworkManager[6192]: <info> Config: added 'ssid' value 'badvista.org'
NetworkManager[6192]: <info> Config: added 'scan_ssid' value '1'
NetworkManager[6192]: <info> Config: added 'key_mgmt' value 'NONE'
NetworkManager[6192]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[6192]: <info> Config: set interface ap_scan to 1
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  disconnected -> scanning
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  scanning -> associating
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  associating -> associated
NetworkManager[6192]: <info> (wlan0): supplicant connection state:  associated -> completed
NetworkManager[6192]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'badvista.org'.
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[6192]: <info> (wlan0): device state change: 5 -> 7 (reason 0)
NetworkManager[6192]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[6192]: nm_setting_ip4_config_get_dhcp_hostname: assertion `NM_IS_SETTING_IP4_CONFIG (setting)' failed
NetworkManager[6192]: <info> dhcpcd started with pid 6370
NetworkManager[6192]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
dhcpcd[6370]: version 5.2.7 starting
dhcpcd[6370]: wlan0: broadcasting for a lease
NetworkManager[6192]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
dhcpcd[6370]: wlan0: offered 192.168.0.104 from 192.168.0.1
dhcpcd[6370]: wlan0: acknowledged 192.168.0.104 from 192.168.0.1
dhcpcd[6370]: wlan0: checking for 192.168.0.104
dhcpcd[6370]: wlan0: leased 192.168.0.104 for 604800 seconds
NetworkManager[6192]: <info> (wlan0): DHCPv4 state changed preinit -> bound
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...
NetworkManager[6192]: <info>   address 192.168.0.104
NetworkManager[6192]: <info>   prefix 24 (255.255.255.0)
NetworkManager[6192]: <info>   gateway 192.168.0.1
NetworkManager[6192]: <info>   nameserver '192.168.0.1'
NetworkManager[6192]: <info>   domain name 'cable.virginmedia.net'
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager[6192]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
NetworkManager[6192]: <info> Clearing nscd hosts cache.
NetworkManager[6192]: <info> (wlan0): device state change: 7 -> 8 (reason 0)
NetworkManager[6192]: <info> Clearing nscd hosts cache.
NetworkManager[6192]: <info> Policy set 'Auto badvista.org' (wlan0) as default for IPv4 routing and DNS.
NetworkManager[6192]: <info> Activation (wlan0) successful, device activated.
NetworkManager[6192]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.