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

[Dan Williams <dcbw redhat com>]

On Wed, 2010-03-10 at 03:52 +0300, 27/249 wrote:
> As usual, after some time there is some new ideas :)
> In short, I found the problem core: NM fails to start wpa_supplicant.
> If I start it manually by command: wpa_supplicant -Dwext -iwlan0 -u
> after starting NM - it works perfectly. So, for now - the question is
> why it doesn't starts automatically and how to make it to do so using
> correct way (of cource I can use a hack and add supplicant to
> rc.networkmanager script, but seems it should be better way).

Ah, so this is dbus service activation.  Do you have this file?

/usr/share/dbus-1/system-services/fi.epitest.hostap.WPASupplicant.service

?  And if so, what does it contain?  It should be something like this:

[D-BUS Service]
Name=fi.epitest.hostap.WPASupplicant
Exec=/usr/sbin/wpa_supplicant -u -f /var/log/wpa_supplicant.log
User=root


Dan

> 
> On Wed, Mar 10, 2010 at 3:27 AM, 27/249 <i27249 gmail com> wrote:
> > 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]
> >
> 
> 
>