From: Marco <netuse@lavabit.com>
To: linux-wireless@vger.kernel.org
Subject: DHCP request timed out, iwlwifi
Date: Mon, 6 Aug 2012 16:14:43 +0200 [thread overview]
Message-ID: <20120806161443.35c71558@homerow> (raw)
[-- Attachment #1: Type: text/plain, Size: 793 bytes --]
Hi,
I use a HP EliteBook equipped with an Intel Centrino Advanced-N 6205
network adapter, it uses the iwlwifi module, on Ubuntu 12.04.
I often cannot connect to my wireless network. Other computers
connect without problems. It is not reproducible, but it occurs, say
once per week. If it doesn't connect, nothing helps, not even a
reboot. I find the following messages in my syslog:
Aug 6 15:34:49 dejon NetworkManager[1042]: <warn> (wlan0): DHCPv4 request
timed out.
The more detailed syslog is attached. DHCP works for all other
computers. If I connect this computer via cable it also works
without problems. So it seems to be related to this particular
computer and its wireless configuration. But I have no clue how to
investigate further.
Any ideas what might be the cause?
Marco
[-- Attachment #2: syslog --]
[-- Type: application/octet-stream, Size: 16580 bytes --]
Aug 6 15:33:58 dejon kernel: [ 1297.076110] cfg80211: Restoring regulatory settings
Aug 6 15:33:58 dejon kernel: [ 1297.076128] cfg80211: Calling CRDA to update world regulatory domain
Aug 6 15:33:58 dejon kernel: [ 1297.085382] cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain
Aug 6 15:33:58 dejon kernel: [ 1297.085392] cfg80211: World regulatory domain updated:
Aug 6 15:33:58 dejon kernel: [ 1297.085396] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Aug 6 15:33:58 dejon kernel: [ 1297.085403] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:33:58 dejon kernel: [ 1297.085409] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:33:58 dejon kernel: [ 1297.085415] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:33:58 dejon kernel: [ 1297.085420] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:33:58 dejon kernel: [ 1297.085426] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Auto-activating connection 'Фузион'.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) starting connection 'Фузион'
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless): access point 'Фузион' has security, but secrets are required.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless): connection 'Фузион' has security, and secrets exist. No new secrets needed.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Config: added 'ssid' value 'Фузион'
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Config: added 'scan_ssid' value '1'
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Config: added 'psk' value '<omitted>'
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> Config: set interface ap_scan to 1
Aug 6 15:34:00 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Aug 6 15:34:04 dejon wpa_supplicant[1947]: Trying to authenticate with 1c:65:9d:a5:62:e5 (SSID='____________' freq=2452 MHz)
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Aug 6 15:34:04 dejon wpa_supplicant[1947]: Trying to associate with 1c:65:9d:a5:62:e5 (SSID='____________' freq=2452 MHz)
Aug 6 15:34:04 dejon kernel: [ 1303.085928] wlan0: authenticate with 1c:65:9d:a5:62:e5 (try 1)
Aug 6 15:34:04 dejon kernel: [ 1303.088312] wlan0: authenticated
Aug 6 15:34:04 dejon kernel: [ 1303.088828] wlan0: associate with 1c:65:9d:a5:62:e5 (try 1)
Aug 6 15:34:04 dejon kernel: [ 1303.091546] wlan0: RX ReassocResp from 1c:65:9d:a5:62:e5 (capab=0x411 status=0 aid=3)
Aug 6 15:34:04 dejon kernel: [ 1303.091549] wlan0: associated
Aug 6 15:34:04 dejon wpa_supplicant[1947]: Associated with 1c:65:9d:a5:62:e5
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: authenticating -> associating
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
Aug 6 15:34:04 dejon wpa_supplicant[1947]: WPA: Key negotiation completed with 1c:65:9d:a5:62:e5 [PTK=CCMP GTK=CCMP]
Aug 6 15:34:04 dejon wpa_supplicant[1947]: CTRL-EVENT-CONNECTED - Connection to 1c:65:9d:a5:62:e5 completed (reauth) [id=0 id_str=]
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'Фузион'.
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> dhclient started with pid 25603
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Aug 6 15:34:04 dejon dhclient: Internet Systems Consortium DHCP Client 4.1-ESV-R4
Aug 6 15:34:04 dejon dhclient: Copyright 2004-2011 Internet Systems Consortium.
Aug 6 15:34:04 dejon dhclient: All rights reserved.
Aug 6 15:34:04 dejon dhclient: For info, please visit https://www.isc.org/software/dhcp/
Aug 6 15:34:04 dejon dhclient:
Aug 6 15:34:04 dejon NetworkManager[1042]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
Aug 6 15:34:04 dejon dhclient: Listening on LPF/wlan0/a0:88:b4:20:61:58
Aug 6 15:34:04 dejon dhclient: Sending on LPF/wlan0/a0:88:b4:20:61:58
Aug 6 15:34:04 dejon dhclient: Sending on Socket/fallback
Aug 6 15:34:04 dejon dhclient: DHCPREQUEST of 10.101.101.36 on wlan0 to 255.255.255.255 port 67
Aug 6 15:34:07 dejon dhclient: DHCPREQUEST of 10.101.101.36 on wlan0 to 255.255.255.255 port 67
Aug 6 15:34:14 dejon kernel: [ 1313.354557] wlan0: no IPv6 routers present
Aug 6 15:34:15 dejon dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 3
Aug 6 15:34:18 dejon dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 7
Aug 6 15:34:25 dejon dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 11
Aug 6 15:34:36 dejon dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 19
Aug 6 15:34:49 dejon NetworkManager[1042]: <warn> (wlan0): DHCPv4 request timed out.
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> (wlan0): canceled DHCP transaction, DHCP client pid 25603
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 4 of 5 (IPv4 Configure Timeout) started...
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> (wlan0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Aug 6 15:34:50 dejon NetworkManager[1042]: <warn> Activation (wlan0) failed for access point (Фузион)
Aug 6 15:34:50 dejon NetworkManager[1042]: <warn> Activation (wlan0) failed.
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> (wlan0): deactivating device (reason 'none') [0]
Aug 6 15:34:50 dejon kernel: [ 1348.948457] wlan0: deauthenticating from 1c:65:9d:a5:62:e5 by local choice (reason=3)
Aug 6 15:34:50 dejon wpa_supplicant[1947]: CTRL-EVENT-DISCONNECTED bssid=00:00:00:00:00:00 reason=3
Aug 6 15:34:50 dejon kernel: [ 1349.051602] cfg80211: All devices are disconnected, going to restore regulatory settings
Aug 6 15:34:50 dejon kernel: [ 1349.051615] cfg80211: Restoring regulatory settings
Aug 6 15:34:50 dejon kernel: [ 1349.051633] cfg80211: Calling CRDA to update world regulatory domain
Aug 6 15:34:50 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: completed -> disconnected
Aug 6 15:34:50 dejon kernel: [ 1349.060469] cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain
Aug 6 15:34:50 dejon kernel: [ 1349.060478] cfg80211: World regulatory domain updated:
Aug 6 15:34:50 dejon kernel: [ 1349.060482] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Aug 6 15:34:50 dejon kernel: [ 1349.060489] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:50 dejon kernel: [ 1349.060495] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:50 dejon kernel: [ 1349.060501] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:50 dejon kernel: [ 1349.060506] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:50 dejon kernel: [ 1349.060512] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Auto-activating connection 'Фузион'.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) starting connection 'Фузион'
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless): access point 'Фузион' has security, but secrets are required.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless): connection 'Фузион' has security, and secrets exist. No new secrets needed.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Config: added 'ssid' value 'Фузион'
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Config: added 'scan_ssid' value '1'
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Config: added 'psk' value '<omitted>'
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Aug 6 15:34:52 dejon NetworkManager[1042]: <info> Config: set interface ap_scan to 1
Aug 6 15:34:52 dejon wpa_supplicant[1947]: Failed to initiate AP scan.
Aug 6 15:34:56 wpa_supplicant[1947]: last message repeated 3 times
Aug 6 15:34:56 dejon wpa_supplicant[1947]: Trying to authenticate with 1c:65:9d:a5:62:e5 (SSID='____________' freq=2452 MHz)
Aug 6 15:34:56 dejon kernel: [ 1354.804737] wlan0: authenticate with 1c:65:9d:a5:62:e5 (try 1)
Aug 6 15:34:56 dejon wpa_supplicant[1947]: Trying to associate with 1c:65:9d:a5:62:e5 (SSID='____________' freq=2452 MHz)
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: disconnected -> associating
Aug 6 15:34:56 dejon kernel: [ 1354.806793] wlan0: authenticated
Aug 6 15:34:56 dejon kernel: [ 1354.807311] wlan0: associate with 1c:65:9d:a5:62:e5 (try 1)
Aug 6 15:34:56 dejon kernel: [ 1354.810094] wlan0: RX ReassocResp from 1c:65:9d:a5:62:e5 (capab=0x411 status=0 aid=3)
Aug 6 15:34:56 dejon kernel: [ 1354.810103] wlan0: associated
Aug 6 15:34:56 dejon wpa_supplicant[1947]: Associated with 1c:65:9d:a5:62:e5
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
Aug 6 15:34:56 dejon wpa_supplicant[1947]: WPA: Key negotiation completed with 1c:65:9d:a5:62:e5 [PTK=CCMP GTK=CCMP]
Aug 6 15:34:56 dejon wpa_supplicant[1947]: CTRL-EVENT-CONNECTED - Connection to 1c:65:9d:a5:62:e5 completed (reauth) [id=0 id_str=]
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'Фузион'.
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> dhclient started with pid 26284
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Aug 6 15:34:56 dejon dhclient: Internet Systems Consortium DHCP Client 4.1-ESV-R4
Aug 6 15:34:56 dejon dhclient: Copyright 2004-2011 Internet Systems Consortium.
Aug 6 15:34:56 dejon dhclient: All rights reserved.
Aug 6 15:34:56 dejon dhclient: For info, please visit https://www.isc.org/software/dhcp/
Aug 6 15:34:56 dejon dhclient:
Aug 6 15:34:56 dejon NetworkManager[1042]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
Aug 6 15:34:56 dejon dhclient: Listening on LPF/wlan0/a0:88:b4:20:61:58
Aug 6 15:34:56 dejon dhclient: Sending on LPF/wlan0/a0:88:b4:20:61:58
Aug 6 15:34:56 dejon dhclient: Sending on Socket/fallback
Aug 6 15:34:56 dejon dhclient: DHCPREQUEST of 10.101.101.36 on wlan0 to 255.255.255.255 port 67
next reply other threads:[~2012-08-06 14:15 UTC|newest]
Thread overview: 7+ messages / expand[flat|nested] mbox.gz Atom feed top
2012-08-06 14:14 Marco [this message]
2012-08-06 16:35 ` DHCP request timed out, iwlwifi Dan Williams
2012-08-06 19:06 ` Marco
2012-08-06 17:28 ` Marco
2012-08-06 19:47 ` Dan Williams
2012-08-06 20:20 ` Marco
2012-09-01 13:14 ` Marco
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20120806161443.35c71558@homerow \
--to=netuse@lavabit.com \
--cc=linux-wireless@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox