| View previous topic :: View next topic |
| Author |
Message |
feystorm
Tux's lil' helper
Joined: 29 Jan 2004
Posts: 96
|
 Posted: Sun May 29, 2011 5:39 am Post subject: NetworkManager tries to bring up eth0 without link |
 |
|
So I've got a system with a wired and wireless link that I'm attempting to manage with NetworkManager (0.8.4.0-r1).
The problem is that when NetworkManager starts, it attempts to bring up eth0, even though there is no link detected (ethtool clearly shows "Link detected: no"). And so NM appears to be timing out on bringing the interface up before it tries to bring up my wireless interface (wlan0).
Is there any way to keep NM from attempting to bring up the wired interface when there isnt even a link on it?
Notice the huge gap in time before it tries to start wlan0 at 23:20:12.
| Code: | May 28 23:19:47 sneaky NetworkManager[1973]: <info> NetworkManager (version 0.8.4.0) is starting...
May 28 23:19:47 sneaky NetworkManager[1973]: <info> Read config file /etc/NetworkManager/nm-system-settings.conf
May 28 23:19:47 sneaky NetworkManager[1973]: <info> trying to start the modem manager...
May 28 23:19:47 sneaky modem-manager[1983]: <info> ModemManager (version 0.4_p20110205) starting...
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Sierra
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Longcheer
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Huawei
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin MotoC
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Ericsson MBM
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin AnyData
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Generic
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Linktop
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin X22X
May 28 23:19:47 sneaky NetworkManager[1973]: <info> monitoring kernel firmware directory '/lib/firmware'.
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Novatel
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin ZTE
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Option High-Speed
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Nokia
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin Gobi
May 28 23:19:47 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Initializing!
May 28 23:19:47 sneaky NetworkManager[1973]: SCPlugin-Ifnet: management mode: managed
May 28 23:19:47 sneaky modem-manager[1983]: <info> Loaded plugin SimTech
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Loading connections
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: guessed connection type (BACKGROUND) = 802-11-wireless
May 28 23:19:48 sneaky modem-manager[1983]: <info> Loaded plugin Option
May 28 23:19:48 sneaky modem-manager[1983]: <info> (ttyUSB0) opening serial port...
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: update_connection_setting_from_config_block: name:BACKGROUND, id:System (BACKGROUND), uuid: c6764626-5322-f534-a090-8ed426cef1b9
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: wireless_setting added for BACKGROUND
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Found error: Unknown config for BACKGROUND
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Found error: Unknown config for BACKGROUND
May 28 23:19:48 sneaky NetworkManager[1973]: nm_connection_verify: assertion `*error == NULL' failed
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Found error: Unknown config for BACKGROUND
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Connection verified BACKGROUND:0
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Hostname updated to: (null)
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: Initialzation complete!
May 28 23:19:48 sneaky NetworkManager[1973]: <info> Loaded plugin ifnet: (C) 1999-2010 Gentoo Foundation, Inc. To report bugs please use bugs.gentoo.org with [networkmanager] or [qiaomuf] prefix.
May 28 23:19:48 sneaky NetworkManager[1973]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc. To report bugs please use the NetworkManager mailing list.
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: getting unmanaged specs...
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: (32638272) ... get_connections.
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: (32638272) connections count: 0
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: parsing stormcloud9 ...
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: read connection 'stormcloud9'
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: parsing artoo ...
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: read connection 'artoo'
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: parsing .keep_net-misc_networkmanager-0 ...
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: error: File permissions (100644) or owner (0) were insecure
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: parsing USA.NET_guest ...
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: read connection 'USA.NET_guest'
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: parsing wired ...
May 28 23:19:48 sneaky NetworkManager[1973]: keyfile: read connection 'wired'
May 28 23:19:48 sneaky NetworkManager[1973]: SCPlugin-Ifnet: getting unmanaged specs...
May 28 23:19:48 sneaky NetworkManager[1973]: <info> WiFi enabled by radio killswitch; enabled by state file
May 28 23:19:48 sneaky NetworkManager[1973]: <info> WWAN enabled by radio killswitch; enabled by state file
May 28 23:19:48 sneaky NetworkManager[1973]: <info> WiMAX enabled by radio killswitch; enabled by state file
May 28 23:19:48 sneaky NetworkManager[1973]: <info> Networking is enabled by state file
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): new 802.11 WiFi device (driver: 'wl1271_sdio' ifindex: 2)
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): now managed
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 1 -> 2 (reason 2)
May 28 23:19:48 sneaky NetworkManager[1973]: <info> (wlan0): bringing up device.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (wlan0): preparing device.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (wlan0): deactivating device (reason: 2).
May 28 23:19:49 sneaky NetworkManager[1973]: supplicant_interface_acquire: assertion `mgr_state == NM_SUPPLICANT_MANAGER_STATE_IDLE' failed
May 28 23:19:49 sneaky NetworkManager[1973]: <error> [1306646389.182464] [nm-device-ethernet.c:763] real_update_permanent_hw_address(): (eth0): unable to read permanent MAC address (error 0)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): carrier is OFF
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): new Ethernet device (driver: 'smsc95xx' ifindex: 3)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/1
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): now managed
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): device state change: 1 -> 2 (reason 2)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): bringing up device.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): preparing device.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): deactivating device (reason: 2).
May 28 23:19:49 sneaky NetworkManager[1973]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> NetworkManager is running with OpenRC...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): carrier now ON (device state 2)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): device state change: 2 -> 3 (reason 40)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> modem-manager is now available
May 28 23:19:49 sneaky NetworkManager[1973]: <warn> bluez error getting default adapter: The name org.bluez was not provided by any .service files
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Trying to start the supplicant...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) starting connection 'wired'
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): device state change: 3 -> 4 (reason 0)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): device state change: 4 -> 5 (reason 0)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): device state change: 5 -> 7 (reason 0)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
May 28 23:19:49 sneaky NetworkManager[1973]: <info> dhcpcd started with pid 2039
May 28 23:19:49 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (wlan0): supplicant manager state: down -> idle
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 2 -> 3 (reason 0)
May 28 23:19:49 sneaky dhcpcd[2039]: version 5.2.12 starting
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (eth0): DHCPv4 state changed nbi -> preinit
May 28 23:19:49 sneaky dhcpcd[2039]: eth0: broadcasting for a lease
May 28 23:19:49 sneaky NetworkManager[1973]: <info> (wlan0): supplicant interface state: starting -> ready
May 28 23:20:00 sneaky modem-manager[1983]: <info> (ttyUSB0) closing serial port...
May 28 23:20:00 sneaky modem-manager[1983]: <info> (ttyUSB0) serial port closed
May 28 23:20:00 sneaky modem-manager[1983]: <info> (ttyUSB0) opening serial port...
May 28 23:20:00 sneaky modem-manager[1983]: <info> (ttyUSB0) closing serial port...
May 28 23:20:00 sneaky modem-manager[1983]: <info> (ttyUSB0) serial port closed
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) starting connection 'stormcloud9'
May 28 23:20:12 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 3 -> 4 (reason 0)
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May 28 23:20:12 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 4 -> 5 (reason 0)
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0/wireless): connection 'stormcloud9' has security, and secrets exist. No new secrets needed.
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Config: added 'ssid' value 'stormcloud9'
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Config: added 'scan_ssid' value '1'
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Config: added 'psk' value '<omitted>'
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 28 23:20:12 sneaky NetworkManager[1973]: <info> Config: set interface ap_scan to 1
May 28 23:20:12 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: inactive -> scanning
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: scanning -> associating
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: associating -> associated
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: associated -> 4-way handshake
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: 4-way handshake -> group handshake
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): supplicant connection state: group handshake -> completed
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'stormcloud9'.
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
May 28 23:20:14 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 5 -> 7 (reason 0)
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Scheduling stage 5
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Done scheduling stage 5
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.
May 28 23:20:14 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
May 28 23:20:15 sneaky NetworkManager[1973]: <info> Clearing nscd hosts cache.
May 28 23:20:15 sneaky NetworkManager[1973]: <info> (wlan0): device state change: 7 -> 8 (reason 0)
May 28 23:20:15 sneaky NetworkManager[1973]: <info> Policy set 'stormcloud9' (wlan0) as default for IPv4 routing and DNS.
May 28 23:20:15 sneaky NetworkManager[1973]: <info> Activation (wlan0) successful, device activated.
May 28 23:20:15 sneaky NetworkManager[1973]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
May 28 23:20:19 sneaky dhcpcd[2039]: timed out
May 28 23:20:19 sneaky NetworkManager[1973]: <info> (eth0): DHCPv4 client pid 2039 exited with status 1
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) started...
May 28 23:20:19 sneaky NetworkManager[1973]: <info> (eth0): device state change: 7 -> 9 (reason 5)
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Marking connection 'wired' invalid.
May 28 23:20:19 sneaky NetworkManager[1973]: <warn> Activation (eth0) failed.
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) complete.
May 28 23:20:19 sneaky NetworkManager[1973]: <info> (eth0): device state change: 9 -> 3 (reason 0)
May 28 23:20:19 sneaky NetworkManager[1973]: <info> (eth0): deactivating device (reason: 0).
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Policy set 'stormcloud9' (wlan0) as default for IPv4 routing and DNS.
May 28 23:20:19 sneaky NetworkManager[1973]: <info> Policy set 'stormcloud9' (wlan0) as default for IPv4 routing and DNS. |
|
|
| Back to top |
|
 |
feystorm
Tux's lil' helper
Joined: 29 Jan 2004
Posts: 96
|
| Posted: Sun May 29, 2011 7:58 am Post subject: |
|
|
Well the delay in staring up my wlan0 interface doesnt appear to be related to eth0. I adjusted the dhcpd timeout to 3 seconds so NM would fail sooner on bringing it up, and theres still a huge lag time before it tries to start wlan0.
Investigating. |
|
| Back to top |
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
Networking & Security
