Re: NetworkManager 0.8 and WiFi on slackware: device not ready

["27/249" <i27249 gmail com>]

Sorry for long waiting. Here is additional info:

tail -f /var/log/messages (cut from NM start):

Mar 10 03:07:49 mac2 NetworkManager: <info>  starting...
Mar 10 03:07:49 mac2 NetworkManager: <info>  Trying to start the
modem-manager...
Mar 10 03:07:49 mac2 NetworkManager: Loaded plugin keyfile: (c) 2007 -
2008 Red Hat, Inc.  To report bugs please use the NetworkManager
mailing list.
Mar 10 03:07:49 mac2 NetworkManager: <info>  Found wlan radio
killswitch rfkill1 (at
/sys/devices/pci0000:00/0000:00:1c.1/0000:02:00.0/ieee80211/phy0/rfkill1)
(driver <unknown>)
Mar 10 03:07:49 mac2 NetworkManager: <info>  WiFi enabled by radio
killswitch; enabled by state file
Mar 10 03:07:49 mac2 NetworkManager: <info>  WWAN enabled by radio
killswitch; enabled by state file
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): carrier is OFF
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): new Ethernet
device (driver: 'sky2')
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): exported as
/org/freedesktop/NetworkManager/Devices/0
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): now managed
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): device state
change: 1 -> 2 (reason 2)
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): preparing device.
Mar 10 03:07:49 mac2 NetworkManager: <info>  (eth0): deactivating
device (reason: 2).
Mar 10 03:07:49 mac2 NetworkManager: Added default wired connection
'Auto eth0' for
/sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/net/eth0
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): driver supports
SSID scans (scan_capa 0x01).
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): new 802.11 WiFi
device (driver: 'iwl3945')
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/NetworkManager/Devices/1
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): now managed
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): device state
change: 1 -> 2 (reason 2)
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): bringing up device.
Mar 10 03:07:49 mac2 kernel: [  481.187348] Registered led device:
iwl-phy0::radio
Mar 10 03:07:49 mac2 kernel: [  481.187370] Registered led device:
iwl-phy0::assoc
Mar 10 03:07:49 mac2 kernel: [  481.187386] Registered led device: iwl-phy0::RX
Mar 10 03:07:49 mac2 kernel: [  481.187402] Registered led device: iwl-phy0::TX
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): preparing device.
Mar 10 03:07:49 mac2 kernel: [  481.191708] ADDRCONF(NETDEV_UP):
wlan0: link is not ready
Mar 10 03:07:49 mac2 NetworkManager: <info>  (wlan0): deactivating
device (reason: 2).
Mar 10 03:07:49 mac2 NetworkManager: <info>  Trying to start the supplicant...
Mar 10 03:09:49 mac2 NetworkManager: <info>  Trying to start the supplicant...

Now I started nm-applet, nothing changed here. When trying to disable
wireless (clicking on checkbox, default: enabled), I got these lines
in /var/log/messages:

Mar 10 03:10:14 mac2 NetworkManager: <info>  (wlan0): taking down device.
Mar 10 03:10:14 mac2 dbus-daemon: Rejected send message, 1 matched
rules; type="method_return", sender=":1.25" (uid=0 pid=3200
comm="/usr/sbin/NetworkManager) interface="(unset)" member="(unset)"
error name="(unset)" requested_reply=0 destination=":1.27" (uid=1000
pid=3230 comm="nm-applet))

Next, when trying to re-enable wireless, I got next lines:

Mar 10 03:10:19 mac2 NetworkManager: <info>  (wlan0): bringing up device.
Mar 10 03:10:19 mac2 kernel: [  631.054359] Registered led device:
iwl-phy0::radio
Mar 10 03:10:19 mac2 kernel: [  631.054790] Registered led device:
iwl-phy0::assoc
Mar 10 03:10:19 mac2 kernel: [  631.054872] Registered led device: iwl-phy0::RX
Mar 10 03:10:19 mac2 kernel: [  631.055211] Registered led device: iwl-phy0::TX
Mar 10 03:10:19 mac2 dbus-daemon: Rejected send message, 1 matched
rules; type="method_return", sender=":1.25" (uid=0 pid=3200
comm="/usr/sbin/NetworkManager) interface="(unset)" member="(unset)"
error name="(unset)" requested_reply=0 destination=":1.27" (uid=1000
pid=3230 comm="nm-applet))
Mar 10 03:10:19 mac2 kernel: [  631.059571] ADDRCONF(NETDEV_UP):
wlan0: link is not ready
Mar 10 03:11:49 mac2 NetworkManager: <info>  Trying to start the supplicant...

As it can be seen above, the "trying to start the supplicant" line
appears every 2 minutes.

Now - rfkill states:

root mac2:~# cat /sys/class/rfkill/*/state
1
1
root mac2:~# cat /sys/class/rfkill/*/type
bluetooth
wlan

Finally, NetworkManager --no-daemon run, it looks most interesting:

root mac2:~# NetworkManager --no-daemon
NetworkManager: <info>  starting...
NetworkManager: <info>  Trying to start the modem-manager...
NetworkManager: Loaded plugin keyfile: (c) 2007 - 2008 Red Hat, Inc.
To report bugs please use the NetworkManager mailing list.
NetworkManager: <info>  Found wlan radio killswitch rfkill1 (at
/sys/devices/pci0000:00/0000:00:1c.1/0000:02:00.0/ieee80211/phy0/rfkill1)
(driver <unknown>)
NetworkManager: <info>  WiFi enabled by radio killswitch; enabled by state file
NetworkManager: <info>  WWAN enabled by radio killswitch; enabled by state file
NetworkManager: <info>  (eth0): carrier is OFF
NetworkManager: <info>  (eth0): new Ethernet device (driver: 'sky2')
NetworkManager: <info>  (eth0): exported as
/org/freedesktop/NetworkManager/Devices/0
NetworkManager: <info>  (eth0): now managed
NetworkManager: <info>  (eth0): device state change: 1 -> 2 (reason 2)
NetworkManager: <info>  (eth0): bringing up device.
NetworkManager: <info>  (eth0): preparing device.
NetworkManager: <info>  (eth0): deactivating device (reason: 2).
NetworkManager: Added default wired connection 'Auto eth0' for
/sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/net/eth0
NetworkManager: <info>  (wlan0): driver supports SSID scans (scan_capa 0x01).
NetworkManager: <info>  (wlan0): new 802.11 WiFi device (driver: 'iwl3945')
NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/NetworkManager/Devices/1
NetworkManager: <info>  (wlan0): now managed
NetworkManager: <info>  (wlan0): device state change: 1 -> 2 (reason 2)
NetworkManager: <info>  (wlan0): bringing up device.
NetworkManager: <info>  (wlan0): preparing device.
NetworkManager: <info>  (wlan0): deactivating device (reason: 2).
NetworkManager: supplicant_interface_acquire: assertion `mgr_state ==
NM_SUPPLICANT_MANAGER_STATE_IDLE' failed
NetworkManager: <WARN>  device_creator():
/sys/devices/virtual/net/vboxnet0: couldn't determine device driver;
ignoring...
-- Error received: File exists
-- Original message: type=0x14 length=56 flags=<REQUEST,ACK,ATOMIC>
sequence-nr=1268180282 pid=4197582
NetworkManager: <WARN>  default_adapter_cb(): bluez error getting
default adapter: The name org.bluez was not provided by any .service
files
NetworkManager: <info>  Trying to start the supplicant...

Seems that problems caused by some "supplicant" misconfiguration (what
supplicant, by the way?).

About possible rfkill issues: the problem doesn't depend on actual
wlan0 state, it can appear even if wifi is actually works at the
moment and connects to the internet (like now I write this mail).

Thanks again and let me know if you need any additional info.

On Sat, Mar 6, 2010 at 10:11 AM, Dan Williams <dcbw redhat com> wrote:
> On Sat, 2010-03-06 at 00:20 +0300, 27/249 wrote:
>> Hi!
>> I'm trying to adapt NetworkManager for MOPSLinux (russian
>> slackware-based distro). Everything works fine, except WiFi -
>> nm-applet tells me that "Device not ready". Actually, device works
>> perfectly if configured manually thru iwconfig or using other tools,
>> so problem is specific to networkmanager.
>> Unfortunately, searching over internet doesn't gave me any progress.
>> What can be a reason of this problem?
>
> Like Andrey suggested, the full NM log output would be useful here.  But
> my first idea is that you have an rfkill switch turned on.  Please also
> get:
>
> cat /sys/class/rfkill/*/state
> cat /sys/class/rfkill/*/type
>
> for me too.  Thanks!
>
> Dan
>
>
>



-- 
Best regards, AiX 27/249 <i27249 gmail com>
[Using null methods]