Attachment 332105 Details for Bug 551862

Extract of NetworkManager log file, with added comments

network tests 1 (text/plain), 16.31 KB, created by Bruno Canning on 2009-12-11 01:54:12 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Bruno Canning

Created: 2009-12-11 01:54:12 UTC

Size: 16.31 KB

patch

obsolete

>Hardware:
>
>PC: HP Compaq NX6110
>CPU: Intel Celeron M 1.4 GHz
>RAM: 512 MiB
>Graphics: Intel 915 GM
>WiFi: Intel PRO 2200BG
>Lan: Broadcom BCM4401
>
>Software:
>
>OS: Linux 2.6.31.5-0.1-default i686
>System: openSUSE 11.2 RC2 (i586) 32 bit
>KDE: 4.3.1 "release 6"
>Installation Medium: openSUSE-KDE4-LiveCD-Build0339-i686.iso
>
>Tests Performed:
>
>2:13 onwards
>started NetworkManager
>activated wireless connection via button on keyboard
>connected to the internet via wireless connection to my modem router (automatic, no further input required after activation)
>pinged an ip address of a computer at college (I am at home), got 4 ping reflections confirming a connection to the internet
>deactivated wireless connection via button on keyboard
>
>2:15 onwards
>connected to the internet via ethernet port to my modem router
>pinged an ip address of a computer at college (I am at home), got 4 ping reflections confirming a connection to the internet
>deactivated connection by physical disconnection
>
>Log retrived and relevant entries chopped out
>MAC addresses and SSID censored, (sorry, I'm sure you're all trustworthy but privacy pays)
>
>Comments:
>
>Everything seemed to work perfectly during these tests but as I said in a previous comment in the bug report, I think it is the punch-out to kdewallet that caused 
>problems the first time I configured the network connections. Kdewallet was configured with now passwords.
>
>Log follows:
>
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  starting...
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <WARN>  nm_generic_enable_loopback(): error -17 returned from rtnl_addr_add():#012Sucess#012
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  Found radio killswitch /org/freedesktop/Hal/devices/ipw_wlan_switch
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  Found new Ethernet device 'eth1' (driver: 'b44').
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  (eth1): exported as /org/freedesktop/Hal/devices/net_00_ff_00_ff_00_ff
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  (eth0): driver supports SSID scans (scan_capa 0x21).
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  Found new 802.11 WiFi device 'eth0' (driver: 'ipw2200').
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_ff_00_ff_00_ff
>Dec 10 02:13:07 linux-vqc4 NetworkManager: <info>  Wireless now disabled by radio killswitch
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 1 -> 2 (reason 2)
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth1): bringing up device.
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth1): preparing device.
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth1): deactivating device (reason: 2).
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 1 -> 2 (reason 2)
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth0): bringing up device.
>Dec 10 02:13:11 linux-vqc4 NetworkManager: <info>  (eth0): deactivating device (reason: 2).
>Dec 10 02:13:25 linux-vqc4 NetworkManager: <info>  Wireless now enabled by radio killswitch
>Dec 10 02:13:25 linux-vqc4 NetworkManager: <info>  (eth0): bringing up device.
>Dec 10 02:13:25 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 2 -> 3 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): supplicant interface state:  starting -> ready
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) starting connection 'myhomenetwork'
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 3 -> 4 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 4 -> 5 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): preparing device.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0/wireless): access point 'myhomenetwork' has security, but secrets are required.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 5 -> 6 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <WARN>  update_one_setting(): Failed to update connection secrets: 1 802-1x
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <WARN>  real_connection_secrets_updated(): Ignoring updated secrets for setting 'ipv4'.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <WARN>  real_connection_secrets_updated(): Ignoring updated secrets for setting '802-11-wireless'.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 6 -> 4 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 4 -> 5 (reason 0)
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0/wireless): connection 'myhomenetwork' has security, and secrets exist.  No new secrets needed.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Config: added 'ssid' value 'myhomenetwork'
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Config: added 'scan_ssid' value '1'
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-PSK'
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Config: added 'psk' value '<omitted>'
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  Config: set interface ap_scan to 1
>Dec 10 02:13:26 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  scanning -> disconnected
>Dec 10 02:13:31 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  disconnected -> scanning
>Dec 10 02:13:31 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  scanning -> associating
>Dec 10 02:13:31 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  associating -> associated
>Dec 10 02:13:31 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  associated -> 4-way handshake
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  4-way handshake -> group handshake
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  group handshake -> completed
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  Activation (eth0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'myhomenetwork'.
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 5 -> 7 (reason 0)
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  Activation (eth0) Beginning DHCP transaction.
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  dhclient started with pid 16246
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
>Dec 10 02:13:32 linux-vqc4 NetworkManager: <info>  DHCP: device eth0 state changed (null) -> preinit
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  DHCP: device eth0 state changed preinit -> bound
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>    address 192.168.2.2
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>    prefix 24 (255.255.255.0)
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>    gateway 192.168.2.1
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>    nameserver '192.168.2.1'
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>    domain name 'myhomenetwork'
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
>Dec 10 02:13:37 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 7 -> 8 (reason 0)
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <debug> [1260411218.038464] run_netconfig(): Spawning '/sbin/netconfig modify --service NetworkManager'
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <debug> [1260411218.067170] write_to_netconfig(): Writing to netconfig: DNSSEARCH='myhomenetwork myhomenetwork'#012
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <debug> [1260411218.067509] write_to_netconfig(): Writing to netconfig: DNSSERVERS='192.168.2.1'#012
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <info>  Clearing nscd hosts cache.
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <info>  Policy set 'myhomenetwork' (eth0) as default for routing and DNS.
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <info>  Activation (eth0) successful, device activated.
>Dec 10 02:13:38 linux-vqc4 NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
>Dec 10 02:13:38 linux-vqc4 nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/autofs' exited with error status 1.
>Dec 10 02:13:48 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  completed -> group handshake
>Dec 10 02:13:48 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  group handshake -> completed
>Dec 10 02:14:06 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  completed -> disconnected
>Dec 10 02:14:06 linux-vqc4 NetworkManager: <info>  (eth0): supplicant connection state:  disconnected -> scanning
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <info>  Wireless now disabled by radio killswitch
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <info>  (eth0): device state change: 8 -> 2 (reason 0)
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <info>  (eth0): deactivating device (reason: 0).
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <info>  eth0: canceled DHCP transaction, dhcp client pid 16246
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <debug> [1260411248.772422] run_netconfig(): Spawning '/sbin/netconfig modify --service NetworkManager'
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <info>  Clearing nscd hosts cache.
>Dec 10 02:14:08 linux-vqc4 NetworkManager: <WARN>  check_one_route(): (eth0) error -34 returned from rtnl_route_del(): Sucess#012
>Dec 10 02:14:08 linux-vqc4 nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/autofs' exited with error status 1.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  (eth1): carrier now ON (device state 2)
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 2 -> 3 (reason 40)
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) starting connection 'System eth1'
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 3 -> 4 (reason 0)
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) started...
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) starting...
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 4 -> 5 (reason 0)
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) successful.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) complete.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) started...
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 5 -> 7 (reason 0)
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Beginning DHCP transaction.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  dhclient started with pid 16639
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.
>Dec 10 02:15:05 linux-vqc4 NetworkManager: <info>  DHCP: device eth1 state changed (null) -> preinit
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  DHCP: device eth1 state changed preinit -> reboot
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) scheduled...
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) started...
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>    address 192.168.2.4
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>    prefix 24 (255.255.255.0)
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>    gateway 192.168.2.1
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>    nameserver '192.168.2.1'
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>    domain name 'myhomenetwork'
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) scheduled...
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 4 of 5 (IP Configure Get) complete.
>Dec 10 02:15:09 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) started...
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 7 -> 8 (reason 0)
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <debug> [1260411310.021396] run_netconfig(): Spawning '/sbin/netconfig modify --service NetworkManager'
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <debug> [1260411310.061240] write_to_netconfig(): Writing to netconfig: DNSSEARCH='myhomenetwork myhomenetwork'#012
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <debug> [1260411310.061594] write_to_netconfig(): Writing to netconfig: DNSSERVERS='192.168.2.1'#012
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <info>  Clearing nscd hosts cache.
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <info>  Policy set 'System eth1' (eth1) as default for routing and DNS.
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <info>  Activation (eth1) successful, device activated.
>Dec 10 02:15:10 linux-vqc4 NetworkManager: <info>  Activation (eth1) Stage 5 of 5 (IP Configure Commit) complete.
>Dec 10 02:15:10 linux-vqc4 nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/autofs' exited with error status 1.
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <info>  (eth1): carrier now OFF (device state 8)
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <info>  (eth1): device state change: 8 -> 2 (reason 40)
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <info>  (eth1): deactivating device (reason: 40).
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <info>  eth1: canceled DHCP transaction, dhcp client pid 16639
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <debug> [1260411321.202709] run_netconfig(): Spawning '/sbin/netconfig modify --service NetworkManager'
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <info>  Clearing nscd hosts cache.
>Dec 10 02:15:21 linux-vqc4 NetworkManager: <WARN>  check_one_route(): (eth1) error -34 returned from rtnl_route_del(): Sucess#012
>Dec 10 02:15:21 linux-vqc4 nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/autofs' exited with error status 1.

Actions: View

Attachments on bug 551862: 332105 | 332106 | 332107