Comment 37 for bug 109887

Revision history for this message
Niels Klomp (nk-careworks) wrote :

I can confirm this bug on a Dell Vostro 1700 running Feisty.

It is definitely related with high network traffic, since it occurs guaranteed within 40 minutes of remote X usage, whilst at other moments it occurs only sporadicly.

This is the worst bug I have ever encountered in the 9 years I am using Linux.

$ uname -a
Linux host 2.6.22-14-generic #1 SMP Sun Oct 14 23:05:12 GMT 2007 i686 GNU/Linux

$ lspci |grep Wireless
0c:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG Network Connection (rev 02)

Nov 27 23:57:02 cw-mobile2 kernel: [15954.176000] ipw3945: Error sending LEDS_CMD: time out after 500ms.
Nov 27 23:57:02 cw-mobile2 kernel: [15954.676000] ipw3945: Error sending cmd #07 to daemon: time out after 500ms.
Nov 27 23:57:04 cw-mobile2 kernel: [15956.172000] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Nov 27 23:57:04 cw-mobile2 kernel: [15956.672000] ipw3945: Error sending cmd #08 to daemon: time out after 500ms.
Nov 27 23:57:05 cw-mobile2 kernel: [15957.172000] ipw3945: Error sending ADD_STA: time out after 500ms.
Nov 27 23:57:05 cw-mobile2 kernel: [15957.672000] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Nov 27 23:57:09 cw-mobile2 kernel: [15961.176000] ipw3945: Error sending LEDS_CMD: time out after 500ms.
Nov 27 23:57:25 cw-mobile2 NetworkManager: <info> eth1: link timed out.
Nov 27 23:57:25 cw-mobile2 NetworkManager: <info> SWITCH: found better connection 'eth1/CareWorksH' than current connection 'eth1/CareWorksH'. same_ssid=1, have_link=0
Nov 27 23:57:25 cw-mobile2 NetworkManager: <info> Will activate connection 'eth1/CareWorksH'.
Nov 27 23:57:25 cw-mobile2 NetworkManager: <info> Device eth1 activation scheduled...
Nov 27 23:57:25 cw-mobile2 NetworkManager: <info> Deactivating device eth1.
Nov 27 23:57:25 cw-mobile2 dhclient: There is already a pid file /var/run/dhclient.eth1.pid with pid 6341
Nov 27 23:57:25 cw-mobile2 dhclient: killed old client process, removed PID file
Nov 27 23:57:25 cw-mobile2 dhclient: DHCPRELEASE on eth1 to 10.14.14.1 port 67
Nov 27 23:57:25 cw-mobile2 avahi-daemon[5784]: Withdrawing address record for 10.14.14.101 on eth1.
Nov 27 23:57:25 cw-mobile2 avahi-daemon[5784]: Leaving mDNS multicast group on interface eth1.IPv4 with address 10.14.14.101.
Nov 27 23:57:25 cw-mobile2 avahi-daemon[5784]: Interface eth1.IPv4 no longer relevant for mDNS.
Nov 27 23:57:26 cw-mobile2 avahi-daemon[5784]: Withdrawing address record for fe80::21b:77ff:fec3:4893 on eth1.
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) started...
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> Activation (eth1/wireless): access point 'CareWorksH' is encrypted, and a key exists. No new key needed.
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface eth1
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> DHCP daemon state is now 11 (unknown) for interface eth1
Nov 27 23:57:26 cw-mobile2 NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface eth1
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> supplicant_interface_init() - connect to global ctrl socket (0/10).
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'INTERFACE_ADD eth1^I^Iwext^I/var/run/wpa_supplicant5^I'
Nov 27 23:57:27 cw-mobile2 kernel: [15979.292000] ADDRCONF(NETDEV_UP): eth1: link is not ready
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> supplicant_init() - connect to device ctrl socket (1/10).
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'AP_SCAN 1'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'ADD_NETWORK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was '0'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 43617265576f726b7348'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA2'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> SUP: response was 'OK'
Nov 27 23:57:27 cw-mobile2 NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Nov 27 23:58:04 cw-mobile2 kernel: [16016.672000] ipw3945: Error sending LEDS_CMD: time out after 500ms.
Nov 27 23:58:05 cw-mobile2 kernel: [16017.172000] ipw3945: Error sending LEDS_CMD: time out after 500ms.
Nov 27 23:58:05 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_get_essid(): error getting ESSID for device eth1: Resource temporarily unavailable
Nov 27 23:58:37 cw-mobile2 last message repeated 16 times
Nov 27 23:59:25 cw-mobile2 last message repeated 24 times
Nov 27 23:59:27 cw-mobile2 NetworkManager: <info> Activation (eth1/wireless): association took too long (>120s), failing activation.
Nov 27 23:59:27 cw-mobile2 NetworkManager: <info> Activation (eth1) failure scheduled...
Nov 27 23:59:27 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_get_essid(): error getting ESSID for device eth1: Resource temporarily unavailable
Nov 27 23:59:27 cw-mobile2 NetworkManager: <info> Activation (eth1) failed for access point (CareWorksH)
Nov 27 23:59:27 cw-mobile2 NetworkManager: <info> Activation (eth1) failed.
Nov 27 23:59:27 cw-mobile2 NetworkManager: <info> Deactivating device eth1.
Nov 27 23:59:27 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_set_essid(): error setting ESSID to '' for device eth1: Resource temporarily unavailable
Nov 27 23:59:27 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_set_wep_enc_key(): error setting key for device eth1: Resource temporarily unavailable
Nov 27 23:59:27 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_get_mode(): error getting card mode on eth1: Resource temporarily unavailable
Nov 27 23:59:27 cw-mobile2 NetworkManager: <WARN> nm_device_802_11_wireless_set_mode(): error setting card eth1 to Infrastructure mode: Resource temporarily unavailable