ndiswrapper/NM Challenges



I wrote earlier about the fact that NetworkManager could see my network, but couldn't connect to it.  I finally figured out how to look at the system log, and although there were a bunch of messages there, this is the one that caught my attention:

Apr  8 20:41:01 localhost NetworkManager: <information> Activation (wlan0/wireless): association took too long (>20s), failing activation.

However, since in all honesty I have no idea what is going on,  I attach the system log, along with a plea for any help anyone can give.

I am running FC5, NetworkManager 0.6.2, ndiswrapper 1.13 (built myself) on a Turion.  I have actually connected to the network twice, but I have no idea what worked those two times and not the rest of the time.

Thanks for any and all help.

John

Apr  8 20:40:36 localhost NetworkManager: <information> User Switch: /org/freedesktop/NetworkManager/Devices/wlan0 / Reading
Apr  8 20:40:36 localhost NetworkManager: <information> Deactivating device wlan0.
Apr  8 20:40:38 localhost dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.reason
Apr  8 20:40:38 localhost NetworkManager: <information> Device wlan0 activation scheduled...
Apr  8 20:40:38 localhost NetworkManager: <information> Deactivating device eth0.
Apr  8 20:40:38 localhost dhclient: DHCPRELEASE on eth0 to 192.168.0.1 port 67
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) started...
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr  8 20:40:39 localhost NetworkManager: <information> Activation (wlan0/wireless): access point 'Reading' is unencrypted, no key needed.
Apr  8 20:40:39 localhost avahi-daemon[2072]: Withdrawing address record for 192.168.0.2 on eth0.
Apr  8 20:40:39 localhost avahi-daemon[2072]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.2.
Apr  8 20:40:39 localhost avahi-daemon[2072]: IP_DROP_MEMBERSHIP failed: No such device
Apr  8 20:40:39 localhost avahi-daemon[2072]: iface.c: interface_mdns_mcast_join() called but no local address available.
Apr  8 20:40:39 localhost avahi-daemon[2072]: Interface eth0.IPv4 no longer relevant for mDNS.
Apr  8 20:40:40 localhost NetworkManager: <information> SUP: sending command 'INTERFACE_ADD wlan0 wext /var/run/wpa_supplicant '
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was 'OK'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: sending command 'AP_SCAN 1'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was 'OK'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: sending command 'ADD_NETWORK'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was '0'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: sending command 'SET_NETWORK 0 ssid 52656164696e67'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was 'OK'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: sending command 'SET_NETWORK 0 key_mgmt NONE'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was 'OK'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: sending command 'ENABLE_NETWORK 0'
Apr  8 20:40:41 localhost NetworkManager: <information> SUP: response was 'OK'
Apr  8 20:40:41 localhost NetworkManager: <information> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Global control interface '/var/run/wpa_supplicant-global'
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): RX global ctrl_iface - hexdump_ascii(len=50):
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      49 4e 54 45 52 46 41 43 45 5f 41 44 44 20 77 6c   INTERFACE_ADD wl
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      61 6e 30 09 09 77 65 78 74 09 2f 76 61 72 2f 72   an0__wext_/var/r
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      75 6e 2f 77 70 61 5f 73 75 70 70 6c 69 63 61 6e   un/wpa_supplican
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      74 09                                             t_              
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE GLOBAL INTERFACE_ADD 'wlan0 wext /var/run/wpa_supplicant '
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Initializing interface 'wlan0' conf 'N/A' driver 'wext' ctrl_interface '/var/run/wpa_supplicant'
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Initializing interface (2) 'wlan0'
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: SUPP_PAE entering state DISCONNECTED
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: KEY_RX entering state NO_KEY_RECEIVE
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: SUPP_BE entering state INITIALIZE
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAP: EAP entering state DISABLED
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: External notification - portEnabled=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: External notification - portValid=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): SIOCGIWRANGE: WE(compiled)=19 WE(source)=18 enc_capa=0xf
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):   capabilities: key_mgmt 0xf enc 0xf
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Own MAC address: 00:14:a4:58:57:7a
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_wpa
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_countermeasures
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_drop_unencrypted
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Setting scan request: 0 sec 100000 usec
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Added interface wlan0
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): Wireless event: cmd=0x8b06 len=12
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=9):
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      41 50 5f 53 43 41 4e 20 31                        AP_SCAN 1       
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=11):
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      41 44 44 5f 4e 45 54 57 4f 52 4b                  ADD_NETWORK     
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE: ADD_NETWORK
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=33):
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      53 45 54 5f 4e 45 54 57 4f 52 4b 20 30 20 73 73   SET_NETWORK 0 ss
Apr  8 20:40:59 localhost NetworkManager: <information> wpa_supplicant(5663):      69 64 20 35 32 36 35 36 31 36 34 36 39 36 65 36   id 52656164696e6
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):      37                                                7               
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE: SET_NETWORK id=0 name='ssid' value='52656164696e67'
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): ssid - hexdump_ascii(len=7):
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): 2 65 61 64 69 6e 67                              Reading         
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=27):
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):      53 45 54 5f 4e 45 54 57 4f 52 4b 20 30 20 6b 65   SET_NETWORK 0 ke
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):      79 5f 6d 67 6d 74 20 4e 4f 4e 45                  y_mgmt NONE     
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE: SET_NETWORK id=0 name='key_mgmt' value='NONE'
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): key_mgmt: 0x4
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=16):
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):      45 4e 41 42 4c 45 5f 4e 45 54 57 4f 52 4b 20 30   ENABLE_NETWORK 0
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE: ENABLE_NETWORK id=0
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Setting scan request: 0 sec 0 usec
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): State: DISCONNECTED -> SCANNING
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Starting AP scan (broadcast SSID)
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): RX ctrl_iface - hexdump_ascii(len=6):
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):      41 54 54 41 43 48                                 ATTACH          
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE monitor attached - hexdump(len=42): 2f 76 61 72 2f 72 75 6e 2f 4e 65 74 77 6f 72 6b 4d 61 6e 61 67 65 72 2f 77 70 61 5f 63 74 72 6c 5f 32 31 39 34 2d 33 00 77 70
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Scan timeout - try to get results
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Received 280 bytes of scan results (1 BSSes)
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Scan results: 1
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Selecting BSS from priority group 0
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): en=0 rsn_ie_len=0 caps=0x1
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):    skip - no WPA/RSN IE
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663):    selected non-WPA AP 00:20:e0:3f:ce:35 ssid='Reading'
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Trying to associate with 00:20:e0:3f:ce:35 (SSID='Reading' freq=2412 MHz)
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): CTRL_IFACE monitor send - hexdump(len=42): 2f 76 61 72 2f 72 75 6e 2f 4e 65 74 77 6f 72 6b 4d 61 6e 61 67 65 72 2f 77 70 61 5f 63 74 72 6c 5f 32 31 39 34 2d 33 00 77 70
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Cancelling scan request
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): WPA: clearing own WPA/RSN IE
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Automatic auth_alg selection: 0x1
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): WPA: clearing AP WPA IE
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): WPA: clearing AP RSN IE
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): WPA: clearing own WPA/RSN IE
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): No keys have been configured - skip key clearing
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_set_drop_unencrypted
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): State: SCANNING -> ASSOCIATING
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): wpa_driver_wext_associate
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Setting authentication timeout: 15 sec 0 usec
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): EAPOL: External notification - portControl=ForceAuthorized
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Wireless event: cmd=0x8b06 len=12
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Wireless event: cmd=0x8b04 len=16
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Wireless event: cmd=0x8b1a len=23
Apr  8 20:41:00 localhost NetworkManager: <information> wpa_supplicant(5663): Authentication with 00:00:00:00:00:00 timed out.
Apr  8 20:41:01 localhost NetworkManager: <information> Activation (wlan0/wireless): association took too long (>20s), failing activation.
Apr  8 20:41:01 localhost NetworkManager: <information> Activation (wlan0) failure scheduled...
Apr  8 20:41:01 localhost NetworkManager: <information> Activation (wlan0) failed for access point (Reading)
Apr  8 20:41:01 localhost NetworkManager: <information> Activation (wlan0) failed.
Apr  8 20:41:01 localhost NetworkManager: <information> Deactivating device wlan0.
Apr  8 20:41:03 localhost NetworkManager: <information> SWITCH: no current connection, found better connection 'eth0'.
Apr  8 20:41:03 localhost NetworkManager: <information> Will activate connection 'eth0'.
Apr  8 20:41:03 localhost NetworkManager: <information> Device eth0 activation scheduled...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) started...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Apr  8 20:41:03 localhost NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Apr  8 20:41:03 localhost gconfd (root-5677): starting (version 2.14.0), pid 5677 user 'root'
Apr  8 20:41:03 localhost gconfd (root-5677): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration source at position 0
Apr  8 20:41:03 localhost gconfd (root-5677): Resolved address "xml:readwrite:/root/.gconf" to a writable configuration source at position 1
Apr  8 20:41:03 localhost gconfd (root-5677): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source at position 2
Apr  8 20:41:04 localhost NetworkManager: <information> Activation (eth0) Beginning DHCP transaction.
Apr  8 20:41:04 localhost NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Apr  8 20:41:04 localhost NetworkManager: <information> DHCP daemon state now 12 for interface eth0
Apr  8 20:41:04 localhost NetworkManager: <information> DHCP daemon state now 1 for interface eth0
Apr  8 20:41:04 localhost dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
Apr  8 20:41:04 localhost dhclient: DHCPOFFER from 192.168.0.1
Apr  8 20:41:04 localhost dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Apr  8 20:41:04 localhost dhclient: DHCPACK from 192.168.0.1
Apr  8 20:41:05 localhost NetworkManager: <information> DHCP daemon state now 2 for interface eth0
Apr  8 20:41:05 localhost NetworkManager: <information> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Apr  8 20:41:05 localhost NetworkManager: <information> Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Apr  8 20:41:05 localhost dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.host_name
Apr  8 20:41:05 localhost dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_domain
Apr  8 20:41:05 localhost dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_servers
Apr  8 20:41:05 localhost NetworkManager: <information> Retrieved the following IP4 configuration from the DHCP daemon:
Apr  8 20:41:05 localhost NetworkManager: <information>   address 192.168.0.2
Apr  8 20:41:05 localhost NetworkManager: <information>   netmask 255.255.255.0
Apr  8 20:41:05 localhost NetworkManager: <information>   broadcast 192.168.0.255
Apr  8 20:41:05 localhost NetworkManager: <information>   gateway 192.168.0.1
Apr  8 20:41:05 localhost NetworkManager: <information>   nameserver 192.168.0.1
Apr  8 20:41:05 localhost NetworkManager: <information>   nameserver 205.171.3.65
Apr  8 20:41:05 localhost NetworkManager: <information>   domain name 'domain.actdsltmp'
Apr  8 20:41:05 localhost dhclient: bound to 192.168.0.2 -- renewal in 36791 seconds.




[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]