Re: NM 0.6.6 doesn't work

[Thomas Ilnseher <illth gmx de>]

A final note first:

[enhancement request]
I would like to see a meaningfull error message like: 
"error, dhcp timeout" or something like that. (in that gui stuff).
Only a symbol that shows "not connected is a bit bad IMHO.
[/enhancement request]

> To get meaningful output, stop NM and start it from command line like:
> NetworkManager --no-daemon
> 
Thank you very much for the info. I finally got the stuff working!!

The problem was that dhclient was waiting due to some option stuff
(??!!!?!=!)

See this:
note tom # /sbin/dhclient -1 -lf /var/lib/dhclient/dhclient-wlan0.leases
-cf /etc/dhcp/dhclient.conf -pf /var/run/dhclient-wlan0.pid   -d wlan0
Internet Systems Consortium DHCP Client V3.1.0-Gentoo
Copyright 2004-2007 Internet Systems Consortium.
All rights reserved.
For info, please visit http://www.isc.org/sw/dhcp/

wmaster0: unknown hardware address type 801
wmaster0: unknown hardware address type 801
Listening on LPF/wlan0/00:1c:26:3b:bc:c2
Sending on   LPF/wlan0/00:1c:26:3b:bc:c2
Sending on   Socket/fallback
option_space_encapsulate: option space agent does not exist, but is
configured.
DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 17
DHCPOFFER from 192.168.2.1
option_space_encapsulate: option space agent does not exist, but is
configured.
DHCPREQUEST on wlan0 to 255.255.255.255 port 67
DHCPREQUEST on wlan0 to 255.255.255.255 port 67
DHCPACK from 192.168.2.1
bound to 192.168.2.34 -- renewal in 1427 seconds.

-- 
i could clearly see that there is a problem that dhclient was waiting
for some option stuff. I lowered dhclient's timeouts. now it works.

For the reference:

note tom # NetworkManager --no-daemon
NetworkManager: <info>  starting...
NetworkManager: <debug> [1226870969.250861] GentooReadConfig(): Enabling
DHCP for device wlan0.
NetworkManager: <debug> [1226870969.251142] GentooReadConfig(): Found
hostname.
NetworkManager: nm_ip4_config_set_hostname: assertion `config != NULL'
failed
NetworkManager: <info>  wlan0: Device is fully-supported using driver
'(null)'.
NetworkManager: <info>  wlan0: driver supports SSID scans (scan_capa
0x01).
NetworkManager: <info>  nm_device_init(): waiting for device's worker
thread to start
NetworkManager: <info>  nm_device_init(): device's worker thread
started, continuing.
NetworkManager: <info>  Now managing wireless (802.11) device 'wlan0'.
NetworkManager: <info>  Deactivating device wlan0.
NetworkManager: <debug> [1226870971.344338] GentooReadConfig(): Found
config_eth0 in /etc/conf.d/net.
NetworkManager: <debug> [1226870971.344617] GentooReadConfig(): Found
routes_eth0 in config.
NetworkManager: <debug> [1226870971.344790] GentooReadConfig(): Found
DNS nameservers in config.
NetworkManager: <debug> [1226870971.344961] GentooReadConfig(): Found
hostname.
NetworkManager: nm_ip4_config_set_hostname: assertion `config != NULL'
failed
NetworkManager: <debug> [1226870971.345242]
nm_system_device_get_system_config(): Using DNS nameservers
"172.16.254.1" from config for device eth0.
NetworkManager: <info>  eth0: Device is fully-supported using driver
'(null)'.
NetworkManager: <info>  nm_device_init(): waiting for device's worker
thread to start
NetworkManager: <info>  nm_device_init(): device's worker thread
started, continuing.
NetworkManager: <info>  Now managing wired Ethernet (802.3) device
'eth0'.
NetworkManager: <info>  Deactivating device eth0.
NetworkManager: <info>  Updating allowed wireless network lists.
NetworkManager: <debug> [1226871024.841917]
nm_device_802_11_wireless_get_activation_ap(): Forcing AP 'tommy'
NetworkManager: <info>  User
Switch: /org/freedesktop/NetworkManager/Devices/wlan0 / tommy
NetworkManager: <info>  Deactivating device wlan0.
NetworkManager: <info>  Device wlan0 activation scheduled...
NetworkManager: <info>  Activation (wlan0) started...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
started...
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
complete.
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) starting...
NetworkManager: <info>  Activation (wlan0/wireless): access point
'tommy' is encrypted, but NO valid key exists.  New key needed.
NetworkManager: <info>  Activation (wlan0) New wireless user key
requested for network 'tommy'.
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) complete.
NetworkManager: <info>  Activation (wlan0) New wireless user key for
network 'tommy' received.
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
started...
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
complete.
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) starting...
NetworkManager: <info>  Activation (wlan0/wireless): access point
'tommy' is encrypted, and a key exists.  No new key needed.
NetworkManager: <info>  SUP: sending command 'INTERFACE_ADD wlan0
wext	/var/run/wpa_supplicant	'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'AP_SCAN 1'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'ADD_NETWORK'
NetworkManager: <info>  SUP: response was '0'
NetworkManager: <info>  SUP: sending command 'SET_NETWORK 0 ssid
746f6d6d79'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'SET_NETWORK 0 proto WPA2'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'SET_NETWORK 0 key_mgmt
WPA-PSK'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'SET_NETWORK 0 psk <key>'
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  SUP: sending command 'ENABLE_NETWORK 0'
CTRL-EVENT-SCAN-RESULTS 
NetworkManager: <info>  SUP: response was 'OK'
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device
Configure) complete.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:18:4d:bc:d5:f6 (SSID='tommy' freq=2422 MHz)
Associated with 00:18:4d:bc:d5:f6
WPA: Key negotiation completed with 00:18:4d:bc:d5:f6 [PTK=CCMP
GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:18:4d:bc:d5:f6 completed (auth)
[id=0 id_str=]
NetworkManager: <info>  Supplicant state changed: 1
NetworkManager: <info>  Activation (wlan0/wireless) Stage 2 of 5 (Device
Configure) successful.  Connected to access point 'tommy'.
NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure
Start) scheduled.
NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure
Start) started...
NetworkManager: <info>  Activation (wlan0) Beginning DHCP transaction.
NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure
Start) complete.
NetworkManager: <info>  DHCP daemon state is now 12 (successfully
started) for interface wlan0
NetworkManager: <info>  DHCP daemon state is now 1 (starting) for
interface wlan0
NetworkManager: <info>  Old device 'wlan0' activating, won't change.
NetworkManager: <info>  DHCP daemon state is now 7 (unknown) for
interface wlan0
NetworkManager: <info>  Device 'wlan0' DHCP transaction took too long
(>45s), stopping it.
NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure
Timeout) scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure
Timeout) started...
NetworkManager: <info>  DHCP daemon state is now 14 (normal exit) for
interface wlan0
NetworkManager: <info>  DHCP daemon state is now 14 (normal exit) for
interface wlan0
NetworkManager: <info>  Activation (wlan0) failure scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure
Timeout) complete.
NetworkManager: <info>  Activation (wlan0) failed for access point
(tommy)
NetworkManager: <info>  Activation (wlan0) failed.
NetworkManager: <info>  Deactivating device wlan0.
CTRL-EVENT-TERMINATING - signal 15 received
^CNetworkManager: <WARN>  nm_signal_handler(): Caught signal 2, shutting
down normally.
NetworkManager: <info>  Caught terminiation signal
NetworkManager: <debug> [1226871140.768289] nm_print_open_socks(): Open
Sockets List:
NetworkManager: <debug> [1226871140.768316] nm_print_open_socks(): Open
Sockets List Done.
NetworkManager: <info>  Deactivating device wlan0.
NetworkManager: <info>  Deactivating device eth0.
note tom # 


>  - Alexander
-- 
Thomas Ilnseher <illth gmx de>