Bug 195411

Summary: Network Manager doesn't work with madwifi any more
Product: [Fedora] Fedora Reporter: Torrey Hoffman <thoffman>
Component: NetworkManagerAssignee: Dan Williams <dcbw>
Status: CLOSED WONTFIX QA Contact:
Severity: medium Docs Contact:
Priority: medium    
Version: 5CC: chemobejk, mail, triage
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard: bzcl34nup
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2008-05-06 16:00:03 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Torrey Hoffman 2006-06-15 02:54:59 UTC
Description of problem:
Network Manager doesn't work with madwifi since upgrading to FC5 from FC4.

Version-Release number of selected component (if applicable):
NetworkManager-0.6.2-2.fc5, madwifi-0.0.0.20060520-6.lvn5

How reproducible: 100%

Steps to Reproduce:
1. Install FC5 with all available updates & fixes
2. Install Livna.org madwifi wireless driver for current kernel
3. Attempt to join a wireless network which used to work under FC4
  
Actual results:
Timeout in join.  (system log pasted below)

Expected results:
If it worked in FC4 it should work in FC5.

Additional info:
Jun 13 08:53:56 moria NetworkManager: <information>     User Switch:
/org/freedesktop/NetworkManager/Devices/ath0 / Arnor
Jun 13 08:53:56 moria NetworkManager: <information>     Deactivating device ath0.
Jun 13 08:53:58 moria dhcdbd: message_handler: message handler not found under
/com/redhat/dhcp/ath0 for sub-path ath0.dbus.get.reason
Jun 13 08:53:58 moria NetworkManager: <information>     Device ath0 activation
scheduled...
Jun 13 08:53:58 moria NetworkManager: <information>     Deactivating device eth0.
Jun 13 08:53:58 moria dhclient: wifi0: unknown hardware address type 801
Jun 13 08:53:58 moria dhclient: wifi0: unknown hardware address type 801
Jun 13 08:53:58 moria dhclient: DHCPRELEASE on eth0 to 192.168.1.1 port 67
Jun 13 08:53:59 moria avahi-daemon[2426]: Withdrawing address record for
192.168.1.44 on eth0.
Jun 13 08:53:59 moria avahi-daemon[2426]: Leaving mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.44.
Jun 13 08:53:59 moria avahi-daemon[2426]: IP_DROP_MEMBERSHIP failed: No such device
Jun 13 08:53:59 moria avahi-daemon[2426]: iface.c: interface_mdns_mcast_join()
called but no local address available.
Jun 13 08:53:59 moria avahi-daemon[2426]: Interface eth0.IPv4 no longer relevant
for mDNS.
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) started...
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) scheduled...
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) started...
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) scheduled...
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) complete.
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) starting...
Jun 13 08:53:59 moria NetworkManager: <information>     Activation
(ath0/wireless): access point 'Arnor' is encrypted, but NO valid key exists. 
New key needed.
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) New
wireless user key requested for network 'Arnor'.
Jun 13 08:53:59 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) complete.
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) New
wireless user key for network 'Arnor' received.
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) scheduled...
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) started...
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) scheduled...
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) Stage
1 of 5 (Device Prepare) complete.
Jun 13 08:54:09 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) starting...
Jun 13 08:54:09 moria NetworkManager: <information>     Activation
(ath0/wireless): access point 'Arnor' is encrypted, and a key exists.  No new
key needed.
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'INTERFACE_ADD ath0                madwifi /var/run/wpa_supplicant  '
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'AP_SCAN 1'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'ADD_NETWORK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was '0'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'SET_NETWORK 0 ssid 41726e6f72'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'SET_NETWORK 0 key_mgmt NONE'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'SET_NETWORK 0 wep_key0 <key>'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'SET_NETWORK 0 wep_tx_keyidx 0'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: sending command
'ENABLE_NETWORK 0'
Jun 13 08:54:10 moria NetworkManager: <information>     SUP: response was 'OK'
Jun 13 08:54:10 moria NetworkManager: <information>     Activation (ath0) Stage
2 of 5 (Device Configure) complete.

Jun 13 08:54:30 moria NetworkManager: <information>     Activation
(ath0/wireless): association took too long (>20s), failing activation.
Jun 13 08:54:30 moria NetworkManager: <information>     Activation (ath0)
failure scheduled...
Jun 13 08:54:30 moria NetworkManager: <information>     Activation (ath0) failed
for access point (Arnor)
Jun 13 08:54:30 moria NetworkManager: <information>     Activation (ath0) failed.
Jun 13 08:54:30 moria NetworkManager: <information>     Deactivating device ath0.
Jun 13 08:54:32 moria NetworkManager: <information>     SWITCH: no current
connection, found better connection 'eth0'.
Jun 13 08:54:32 moria NetworkManager: <information>     Will activate connection
'eth0'.
Jun 13 08:54:32 moria NetworkManager: <information>     Device eth0 activation
scheduled...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) started...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
1 of 5 (Device Prepare) scheduled...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
1 of 5 (Device Prepare) started...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
2 of 5 (Device Configure) scheduled...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
1 of 5 (Device Prepare) complete.
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
2 of 5 (Device Configure) starting...
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
2 of 5 (Device Configure) successful.
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
3 of 5 (IP Configure Start) scheduled.
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
2 of 5 (Device Configure) complete.
Jun 13 08:54:32 moria NetworkManager: <information>     Activation (eth0) Stage
3 of 5 (IP Configure Start) started...
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0)
Beginning DHCP transaction.
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
3 of 5 (IP Configure Start) complete.
Jun 13 08:54:34 moria dhclient: wifi0: unknown hardware address type 801
Jun 13 08:54:34 moria NetworkManager: <information>     DHCP daemon state is now
12 (successfully started) for interface eth0
Jun 13 08:54:34 moria NetworkManager: <information>     DHCP daemon state is now
1 (starting) for interface eth0
Jun 13 08:54:34 moria dhclient: wifi0: unknown hardware address type 801
Jun 13 08:54:34 moria dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67
interval 7
Jun 13 08:54:34 moria dhclient: DHCPOFFER from 192.168.1.1
Jun 13 08:54:34 moria dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Jun 13 08:54:34 moria dhclient: DHCPACK from 192.168.1.1
Jun 13 08:54:34 moria dhclient: bound to 192.168.1.44 -- renewal in 35883 seconds.
Jun 13 08:54:34 moria NetworkManager: <information>     DHCP daemon state is now
2 (bound) for interface eth0
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
4 of 5 (IP Configure Get) scheduled...
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
4 of 5 (IP Configure Get) started...
Jun 13 08:54:34 moria dhcdbd: message_handler: message handler not found under
/com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.host_name
Jun 13 08:54:34 moria dhcdbd: message_handler: message handler not found under
/com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_domain
Jun 13 08:54:34 moria dhcdbd: message_handler: message handler not found under
/com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.nis_servers
Jun 13 08:54:34 moria NetworkManager: <information>     Retrieved the following
IP4 configuration from the DHCP daemon:
Jun 13 08:54:34 moria NetworkManager: <information>       address 192.168.1.44
Jun 13 08:54:34 moria NetworkManager: <information>       netmask 255.255.255.0
Jun 13 08:54:34 moria NetworkManager: <information>       broadcast 192.168.1.255
Jun 13 08:54:34 moria NetworkManager: <information>       gateway 192.168.1.1
Jun 13 08:54:34 moria NetworkManager: <information>       nameserver 192.168.1.1
Jun 13 08:54:34 moria NetworkManager: <information>       nameserver 66.93.87.2
Jun 13 08:54:34 moria NetworkManager: <information>       nameserver 216.231.41.2
Jun 13 08:54:34 moria NetworkManager: <information>       domain name 'arnor.net'
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
5 of 5 (IP Configure Commit) scheduled...
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
4 of 5 (IP Configure Get) complete.
Jun 13 08:54:34 moria NetworkManager: <information>     Activation (eth0) Stage
5 of 5 (IP Configure Commit) started...
Jun 13 08:54:34 moria avahi-daemon[2426]: New relevant interface eth0.IPv4 for mDNS.
Jun 13 08:54:34 moria avahi-daemon[2426]: Joining mDNS multicast group on
interface eth0.IPv4 with address 192.168.1.44.
Jun 13 08:54:34 moria avahi-daemon[2426]: Registering new address record for
192.168.1.44 on eth0.
Jun 13 08:54:35 moria NetworkManager: <information>     Activation (eth0) Finish
handler scheduled.
Jun 13 08:54:35 moria NetworkManager: <information>     Activation (eth0) Stage
5 of 5 (IP Configure Commit) complete.
Jun 13 08:54:35 moria NetworkManager: <information>     Activation (eth0)
successful, device activated.

Comment 1 Dan Williams 2006-07-09 23:51:04 UTC
Is the madwifi driver from livna "madwifi" or "madwifi-ng", and what SVN
revision is it?

Comment 2 Torrey Hoffman 2006-07-10 16:28:39 UTC
I believe it was madwifi-ng -- as I mentioned in the original bug report, it was
"madwifi-0.0.0.20060520-6.lvn5".  

However the machine in question is now running Ubuntu, (which does not have this
problem) so I can't investigate further.





Comment 3 Stefan Becker 2006-09-10 09:28:34 UTC
NetworkManager-0.6.4-1.fc5 still has the special case code to request the driver
"madwifi" instead of "wext" from wpa_supplicant when it detects the ath_pci
driver. The NetworkManager packager in Rawhide for FC6 dropped this patch already.

From the log above:

INTERFACE_ADD ath0                madwifi /var/run/wpa_supplicant 

But the latest madwifi releases, e.g. 0.9.2, implement wireless extension
support, making the madwifi driver in wpa_supplicant unnecessary. When I ran
wpa_supplicant by hand my access point was only recognized with the following
combinations:

   driver madwifi      AP_SCAN 1
   driver wext         AP_SCAN 2

On my machine NetworkManager always uses AP_SCAN=2, although in the log above it
uses AP_SCAN 1:

NetworkManager: <information>     SUP: sending command 'AP_SCAN 1'

I don't know how NetworkManager decides to use AP_SCAN 1 or 2. Anyway I modified
the string "ath_pci" in /usr/sbin/NetworkManager and now it requests the wext
driver from wpa_supplicant and everything works OK for me.

The easiest way to test this is to run wpa_supplicant by hand as root with the
following configuration file:

------------------------ test.conf --------------------------
ctrl_interface=/var/run/wpa_supplicant
ctrl_interface_group=0
ap_scan=2
network={
        ssid="Arnor"
        scan_ssid=1
        key_mgmt=NONE
        wep_key0=<insert your WEP key here>
        wep_tx_keyidx=0
}
------------------------ test.conf --------------------------

Try which of the following commands creates a valid association with the AP:

  # wpa_supplicant -dd -c test.conf -D madwifi -i ath0
  # wpa_supplicant -dd -c test.conf -D wext -i ath0

Try the same commands with ap_scan=1. Now the result should be reversed.

Comment 4 Joachim Selke 2006-09-29 09:38:22 UTC
I have exactly the same problem on an FC5 notebook here. Installing the FC6
devel RPM of NetworkManager is not an option to fix this bug because this RPM's
dependencies require a lot of RPMs to be updated to devel.

So NetworkManager is completely useless for me on this notebook at the moment.
It would be a great help if there is a fix of this bug for FC5.

Comment 5 Bug Zapper 2008-04-04 03:05:21 UTC
Fedora apologizes that these issues have not been resolved yet. We're
sorry it's taken so long for your bug to be properly triaged and acted
on. We appreciate the time you took to report this issue and want to
make sure no important bugs slip through the cracks.

If you're currently running a version of Fedora Core between 1 and 6,
please note that Fedora no longer maintains these releases. We strongly
encourage you to upgrade to a current Fedora release. In order to
refocus our efforts as a project we are flagging all of the open bugs
for releases which are no longer maintained and closing them.
http://fedoraproject.org/wiki/LifeCycle/EOL

If this bug is still open against Fedora Core 1 through 6, thirty days
from now, it will be closed 'WONTFIX'. If you can reporduce this bug in
the latest Fedora version, please change to the respective version. If
you are unable to do this, please add a comment to this bug requesting
the change.

Thanks for your help, and we apologize again that we haven't handled
these issues to this point.

The process we are following is outlined here:
http://fedoraproject.org/wiki/BugZappers/F9CleanUp

We will be following the process here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping to ensure this
doesn't happen again.

And if you'd like to join the bug triage team to help make things
better, check out http://fedoraproject.org/wiki/BugZappers

Comment 6 Bug Zapper 2008-05-06 16:00:02 UTC
This bug is open for a Fedora version that is no longer maintained and
will not be fixed by Fedora. Therefore we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen thus bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.