[Pkg-utopia-maintainers] Bug#714951: network-manager: NM ceased to handle Aironet wireless card

Roland Mas lolando at debian.org
Thu Jul 4 15:26:12 UTC 2013


Package: network-manager
Version: 0.9.4.0-10
Severity: important

Dear Maintainer,

It seems that NM in Wheezy no longer likes my (admittedly old, but still
working) Cisco Aironet 350 PCMCIA wireless card; the kernel driver is
still operational, since I can use the card if I configure it manually.

The following is a record of what I see in /var/log/syslog, interspersed
with what I typed in a root shell to investigate.  I started with the NM
service shut down, and the card not plugged in.

First, I insert the PCMCIA card:

Jul  4 16:00:41 elastomir kernel: [24027.400122] pcmcia_socket pcmcia_socket0: pccard: PCMCIA card inserted into slot 0
Jul  4 16:00:41 elastomir kernel: [24027.400400] pcmcia 0.0: pcmcia: registering new device pcmcia0.0 (IRQ: 3)
Jul  4 16:00:42 elastomir kernel: [24028.706381] airo(): cmd:111 status:7f11 rsp0:2 rsp1:0 rsp2:0
Jul  4 16:00:42 elastomir kernel: [24028.706394] airo(): Doing fast bap_reads
Jul  4 16:00:42 elastomir kernel: [24028.720680] airo(eth1): Firmware version 5.41.00
Jul  4 16:00:42 elastomir kernel: [24028.720686] airo(eth1): WPA supported.
Jul  4 16:00:42 elastomir kernel: [24028.720690] airo(eth1): MAC enabled 00:0d:bc:3a:e5:4c

Then I run:
# ifconfig eth1 up:

Jul  4 16:00:55 elastomir avahi-daemon[1668]: Joining mDNS multicast group on interface eth1.IPv6 with address fe80::20d:bcff:fe3a:e54c.
Jul  4 16:00:55 elastomir avahi-daemon[1668]: New relevant interface eth1.IPv6 for mDNS.
Jul  4 16:00:55 elastomir avahi-daemon[1668]: Registering new address record for fe80::20d:bcff:fe3a:e54c on eth1.*.
Jul  4 16:00:56 elastomir ntpd[2095]: Listen normally on 26 eth1 fe80::20d:bcff:fe3a:e54c UDP 123
Jul  4 16:00:56 elastomir ntpd[2095]: peers refreshed
Jul  4 16:01:04 elastomir kernel: [24051.168055] eth1: no IPv6 routers present

Then:
# iwlist eth1 scan
This returns one particular cell of interest:

eth1      Scan completed :
[...]
          Cell 02 - Address: 14:0C:76:F9:23:BD
                    ESSID:"FreeWifi"
                    Mode:Master
                    Frequency:2.472 GHz (Channel 13)
                    Quality=10/100  Signal level=-90 dBm  Noise level:0 dBm
                    Encryption key:off
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s; 6 Mb/s
                              9 Mb/s; 12 Mb/s; 18 Mb/s
                    Extra:bcn_int=96
[...]

So I configure the card to use that ESSID:
# iwconfig eth1 essid FreeWifi
# iwconfig eth1 
eth1      IEEE 802.11-DS  ESSID:"FreeWifi"  
          Mode:Managed  Frequency:2.412 GHz  Access Point: 14:0C:76:F9:23:BD   
          Bit Rate:5.5 Mb/s   Tx-Power=20 dBm   Sensitivity=0/65535  
          Retry limit:16   RTS thr:off   Fragment thr:off
          Encryption key:off
          Power Management:off
          Link Quality=12/100  Signal level=-89 dBm  Noise level=-92 dBm
          Rx invalid nwid:93  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:0  Invalid misc:246   Missed beacon:0

And I run a DHCP client on it:
# dhclient eth1
# ifconfig eth1
eth1      Link encap:Ethernet  HWaddr 00:0d:bc:3a:e5:4c  
          inet adr:78.251.230.13  Bcast:78.251.255.255  Masque:255.255.128.0
          adr inet6: fe80::20d:bcff:fe3a:e54c/64 Scope:Lien
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:3 errors:213 dropped:0 overruns:0 frame:213
          TX packets:47 errors:14 dropped:0 overruns:0 carrier:14
          collisions:94 lg file transmission:1000 
          RX bytes:708 (708.0 B)  TX bytes:22257 (21.7 KiB)
          Interruption:3 Adresse de base:0x100 


Jul  4 16:01:32 elastomir dhclient: DHCPDISCOVER on eth1 to 255.255.255.255 port 67 interval 4
Jul  4 16:01:33 elastomir dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Jul  4 16:01:33 elastomir dhclient: DHCPOFFER from 78.251.255.252
Jul  4 16:01:33 elastomir dhclient: DHCPACK from 78.251.255.252
Jul  4 16:01:33 elastomir avahi-daemon[1668]: Joining mDNS multicast group on interface eth1.IPv4 with address 78.251.230.13.
Jul  4 16:01:33 elastomir avahi-daemon[1668]: New relevant interface eth1.IPv4 for mDNS.
Jul  4 16:01:33 elastomir avahi-daemon[1668]: Registering new address record for 78.251.230.13 on eth1.IPv4.
Jul  4 16:01:34 elastomir dhclient: bound to 78.251.230.13 -- renewal in 54 seconds.
Jul  4 16:01:34 elastomir ntpd[2095]: Listen normally on 27 eth1 78.251.230.13 UDP 123
Jul  4 16:01:34 elastomir ntpd[2095]: peers refreshed

So the card works and the kernel driver is fine too.  Now let's try NM
again.  First I eject the PCMCIA card:

Jul  4 16:01:58 elastomir kernel: [24105.030392] pcmcia_socket pcmcia_socket0: pccard: card ejected from slot 0
Jul  4 16:01:58 elastomir kernel: [24105.030578] airo(eth1): cmd:2 status:ffff rsp0:ffff rsp1:ffff rsp2:ffff
Jul  4 16:01:58 elastomir kernel: [24105.030779] airo(eth1): cmd:21 status:ffff rsp0:ffff rsp1:ffff rsp2:ffff
Jul  4 16:01:58 elastomir kernel: [24105.035690] airo(eth1): cmd:21 status:ffff rsp0:ffff rsp1:ffff rsp2:ffff
Jul  4 16:01:58 elastomir dhclient: receive_packet failed on eth1: Network is down
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Interface eth1.IPv6 no longer relevant for mDNS.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Leaving mDNS multicast group on interface eth1.IPv6 with address fe80::20d:bcff:fe3a:e54c.
Jul  4 16:01:58 elastomir kernel: [24105.048375] airo(eth1): cmd:21 status:ffff rsp0:ffff rsp1:ffff rsp2:ffff
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Interface eth1.IPv4 no longer relevant for mDNS.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Leaving mDNS multicast group on interface eth1.IPv4 with address 78.251.230.13.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Withdrawing address record for fe80::20d:bcff:fe3a:e54c on eth1.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Withdrawing address record for 78.251.230.13 on eth1.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Withdrawing workstation service for eth1.
Jul  4 16:01:58 elastomir avahi-daemon[1668]: Withdrawing workstation service for wifi0.
Jul  4 16:01:59 elastomir ntpd[2095]: Deleting interface #27 eth1, 78.251.230.13#123, interface stats: received=0, sent=4, dropped=0, active_time=25 secs
Jul  4 16:01:59 elastomir ntpd[2095]: 88.191.227.26 interface 78.251.230.13 -> (none)
Jul  4 16:01:59 elastomir ntpd[2095]: 88.190.34.44 interface 78.251.230.13 -> (none)
Jul  4 16:01:59 elastomir ntpd[2095]: 88.190.14.112 interface 78.251.230.13 -> (none)
Jul  4 16:01:59 elastomir ntpd[2095]: 91.121.60.158 interface 78.251.230.13 -> (none)
Jul  4 16:01:59 elastomir ntpd[2095]: Deleting interface #26 eth1, fe80::20d:bcff:fe3a:e54c#123, interface stats: received=0, sent=0, dropped=0, active_time=63 secs
Jul  4 16:01:59 elastomir ntpd[2095]: peers refreshed

Then I restart NM:
# service network-manager start

ul  4 16:02:08 elastomir NetworkManager[12446]: <info> NetworkManager (version 0.9.4.0) is starting...
Jul  4 16:02:08 elastomir NetworkManager[12446]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
Jul  4 16:02:08 elastomir NetworkManager[12446]: <info> VPN: loaded org.freedesktop.NetworkManager.openvpn
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: init!
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: update_system_hostname
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPluginIfupdown: guessed connection type (vmtap0) = 802-3-ethernet
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: update_connection_setting_from_if_block: name:vmtap0, type:802-3-ethernet, id:Ifupdown (vmtap0), uuid: 9f19acb8-33cc-7db4-2ce5-8e68b3344ca9
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: adding vmtap0 to iface_connections
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: adding iface vmtap0 to well_known_interfaces
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: found bridge ports vmtap0 for br0
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: adding bridge port vmtap0 to well_known_interfaces
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: autoconnect
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPluginIfupdown: management mode: unmanaged
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:12.0/net/eth0, iface: eth0)
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:12.0/net/eth0, iface: eth0): no ifupdown configuration found.
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/br0, iface: br0)
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/br0, iface: br0): no ifupdown configuration found.
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/lo, iface: lo)
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/lo, iface: lo): no ifupdown configuration found.
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/vmtap0, iface: vmtap0)
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPluginIfupdown: locking wired connection setting
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: end _init.
Jul  4 16:02:08 elastomir NetworkManager[12446]: <info> Loaded plugin ifupdown: (C) 2008 Canonical Ltd.  To report bugs please use the NetworkManager mailing list.
Jul  4 16:02:08 elastomir NetworkManager[12446]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Jul  4 16:02:08 elastomir NetworkManager[12446]:    Ifupdown: get unmanaged devices count: 1
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: (153866936) ... get_connections.
Jul  4 16:02:08 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: (153866936) ... get_connections (managed=false): return empty list.
[Plenty of configured connections show up, including:]
Jul  4 16:02:08 elastomir NetworkManager[12446]:    keyfile: parsing FreeWifi ...
Jul  4 16:02:09 elastomir NetworkManager[12446]:    keyfile:     read connection 'FreeWifi'
[More of those parsing/read connection]
Jul  4 16:02:09 elastomir NetworkManager[12446]:    Ifupdown: get unmanaged devices count: 1
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> modem-manager is now available
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> monitoring kernel firmware directory '/lib/firmware'.
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> monitoring ifupdown state file '/run/network/ifstate'.
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> WiFi enabled by radio killswitch; enabled by state file
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> WWAN enabled by radio killswitch; enabled by state file
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> WiMAX enabled by radio killswitch; enabled by state file
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> Networking is enabled by state file
Jul  4 16:02:09 elastomir NetworkManager[12446]: <warn> failed to allocate link cache: (-10) Operation not supported
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): carrier is OFF
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): new Ethernet device (driver: 'via-rhine' ifindex: 2)
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): now managed
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): preparing device.
Jul  4 16:02:09 elastomir NetworkManager[12446]: <info> (eth0): deactivating device (reason 'managed') [2]
Jul  4 16:02:09 elastomir NetworkManager[12446]: <warn> /sys/devices/virtual/net/br0: couldn't determine device driver; ignoring...
Jul  4 16:02:09 elastomir NetworkManager[12446]: <warn> /sys/devices/virtual/net/vmtap0: couldn't determine device driver; ignoring...
Jul  4 16:02:09 elastomir NetworkManager[12446]: <warn> /sys/devices/virtual/net/br0: couldn't determine device driver; ignoring...
Jul  4 16:02:09 elastomir NetworkManager[12446]: <warn> /sys/devices/virtual/net/vmtap0: couldn't determine device driver; ignoring...

Okay, so NM is now started.  Let me insert the card again:

Jul  4 16:02:23 elastomir kernel: [24129.904114] pcmcia_socket pcmcia_socket0: pccard: PCMCIA card inserted into slot 0
Jul  4 16:02:23 elastomir kernel: [24129.904394] pcmcia 0.0: pcmcia: registering new device pcmcia0.0 (IRQ: 3)
Jul  4 16:02:24 elastomir kernel: [24131.226401] airo(): cmd:111 status:7f11 rsp0:2 rsp1:0 rsp2:0
Jul  4 16:02:24 elastomir kernel: [24131.226414] airo(): Doing fast bap_reads
Jul  4 16:02:24 elastomir kernel: [24131.244724] airo(eth1): Firmware version 5.41.00
Jul  4 16:02:24 elastomir kernel: [24131.244730] airo(eth1): WPA supported.
Jul  4 16:02:24 elastomir kernel: [24131.244736] airo(eth1): MAC enabled 00:0d:bc:3a:e5:4c
Jul  4 16:02:24 elastomir NetworkManager[12446]: <warn> failed to allocate link cache: (-10) Operation not supported
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): driver does not support SSID scans (scan_capa 0x00).
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): using WEXT for WiFi device control
Jul  4 16:02:24 elastomir NetworkManager[12446]: <error> [1372946544.983937] [nm-device-wifi.c:2590] real_update_permanent_hw_address(): (eth1): unable to read permanent MAC address (error 95)
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): new 802.11 WiFi device (driver: 'airo_cs' ifindex: 16)
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/1
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): now managed
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jul  4 16:02:24 elastomir NetworkManager[12446]: <info> (eth1): bringing up device.
Jul  4 16:02:25 elastomir NetworkManager[12446]: <info> (eth1): preparing device.
Jul  4 16:02:25 elastomir NetworkManager[12446]: <info> (eth1): deactivating device (reason 'managed') [2]
Jul  4 16:02:25 elastomir wpa_supplicant[1700]: nl80211: 'nl80211' generic netlink not found
Jul  4 16:02:25 elastomir wpa_supplicant[1700]: Failed to initialize driver 'nl80211'
Jul  4 16:02:25 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:09.0/0.0/net/eth1, iface: eth1)
Jul  4 16:02:25 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:09.0/0.0/net/eth1, iface: eth1): no ifupdown configuration found.
Jul  4 16:02:25 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:09.0/0.0/net/wifi0, iface: wifi0)
Jul  4 16:02:25 elastomir NetworkManager[12446]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:09.0/0.0/net/wifi0, iface: wifi0): no ifupdown configuration found.
Jul  4 16:02:25 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Jul  4 16:02:25 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Jul  4 16:02:25 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: starting -> ready
Jul  4 16:02:25 elastomir NetworkManager[12446]: <info> (eth1): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Jul  4 16:02:25 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: ready -> inactive
Jul  4 16:02:25 elastomir NetworkManager[12446]: <warn> Trying to remove a non-existant call id.
Jul  4 16:02:26 elastomir avahi-daemon[1668]: Joining mDNS multicast group on interface eth1.IPv6 with address fe80::20d:bcff:fe3a:e54c.
Jul  4 16:02:26 elastomir avahi-daemon[1668]: New relevant interface eth1.IPv6 for mDNS.
Jul  4 16:02:26 elastomir avahi-daemon[1668]: Registering new address record for fe80::20d:bcff:fe3a:e54c on eth1.*.
Jul  4 16:02:27 elastomir ntpd[2095]: Listen normally on 28 eth1 fe80::20d:bcff:fe3a:e54c UDP 123
Jul  4 16:02:27 elastomir ntpd[2095]: peers refreshed
Jul  4 16:02:28 elastomir dhclient: DHCPREQUEST on eth1 to 78.251.255.254 port 67
Jul  4 16:02:28 elastomir dhclient: send_packet: Network is unreachable
Jul  4 16:02:28 elastomir dhclient: send_packet: please consult README file regarding broadcast address.
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Auto-activating connection 'FreeWifi'.
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) starting connection 'FreeWifi'
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> (eth1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> (eth1): device state change: prepare -> config (reason 'none') [40 50 0]
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1/wireless): connection 'FreeWifi' requires no security.  No secrets needed.
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Config: added 'ssid' value 'FreeWifi'
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Config: added 'scan_ssid' value '1'
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Config: added 'key_mgmt' value 'NONE'
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> Config: set interface ap_scan to 1
Jul  4 16:02:28 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: inactive -> scanning
Jul  4 16:02:31 elastomir dhclient: DHCPREQUEST on eth1 to 78.251.255.254 port 67
Jul  4 16:02:31 elastomir dhclient: send_packet: Network is unreachable
Jul  4 16:02:31 elastomir dhclient: send_packet: please consult README file regarding broadcast address.
Jul  4 16:02:31 elastomir wpa_supplicant[1700]: eth1: Trying to associate with 14:0c:76:f9:23:bd (SSID='FreeWifi' freq=2472 MHz)
Jul  4 16:02:31 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWGENIE]: Operation not supported
Jul  4 16:02:31 elastomir wpa_supplicant[1700]: eth1: Association request to the driver failed
Jul  4 16:02:31 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: scanning -> associating
Jul  4 16:02:36 elastomir wpa_supplicant[1700]: eth1: Authentication with 14:0c:76:f9:23:bd timed out.
Jul  4 16:02:36 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: associating -> disconnected
Jul  4 16:02:37 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: disconnected -> scanning
Jul  4 16:02:38 elastomir dhclient: DHCPREQUEST on eth1 to 78.251.255.254 port 67
Jul  4 16:02:38 elastomir dhclient: send_packet: Network is unreachable
Jul  4 16:02:38 elastomir dhclient: send_packet: please consult README file regarding broadcast address.
Jul  4 16:02:40 elastomir wpa_supplicant[1700]: eth1: Trying to associate with 14:0c:76:f9:23:bd (SSID='FreeWifi' freq=2472 MHz)
Jul  4 16:02:40 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWGENIE]: Operation not supported
Jul  4 16:02:40 elastomir wpa_supplicant[1700]: eth1: Association request to the driver failed
Jul  4 16:02:40 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: scanning -> associating
Jul  4 16:02:45 elastomir wpa_supplicant[1700]: eth1: Authentication with 14:0c:76:f9:23:bd timed out.
Jul  4 16:02:45 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: associating -> disconnected
Jul  4 16:02:46 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: disconnected -> scanning
Jul  4 16:02:49 elastomir wpa_supplicant[1700]: eth1: Trying to associate with 14:0c:76:f9:23:bd (SSID='FreeWifi' freq=2472 MHz)
Jul  4 16:02:49 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWGENIE]: Operation not supported
Jul  4 16:02:49 elastomir wpa_supplicant[1700]: eth1: Association request to the driver failed
Jul  4 16:02:49 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: scanning -> associating
Jul  4 16:02:49 elastomir dhclient: DHCPREQUEST on eth1 to 78.251.255.254 port 67
Jul  4 16:02:49 elastomir dhclient: send_packet: Network is unreachable
Jul  4 16:02:49 elastomir dhclient: send_packet: please consult README file regarding broadcast address.
Jul  4 16:02:53 elastomir NetworkManager[12446]: <warn> Activation (eth1/wireless): association took too long, failing activation.
Jul  4 16:02:53 elastomir NetworkManager[12446]: <info> (eth1): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Jul  4 16:02:53 elastomir NetworkManager[12446]: <warn> Activation (eth1) failed for access point (FreeWifi)
Jul  4 16:02:53 elastomir NetworkManager[12446]: <warn> Activation (eth1) failed.
Jul  4 16:02:53 elastomir NetworkManager[12446]: <info> (eth1): device state change: failed -> disconnected (reason 'none') [120 30 0]
Jul  4 16:02:53 elastomir NetworkManager[12446]: <info> (eth1): deactivating device (reason 'none') [0]
Jul  4 16:02:53 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: associating -> disconnected
Jul  4 16:02:53 elastomir NetworkManager[12446]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Auto-activating connection 'FreeWifi'.
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) starting connection 'FreeWifi'
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> (eth1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> (eth1): device state change: prepare -> config (reason 'none') [40 50 0]
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1/wireless): connection 'FreeWifi' requires no security.  No secrets needed.
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Config: added 'ssid' value 'FreeWifi'
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Config: added 'scan_ssid' value '1'
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Config: added 'key_mgmt' value 'NONE'
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> Config: set interface ap_scan to 1
Jul  4 16:02:56 elastomir NetworkManager[12446]: <info> (eth1): supplicant interface state: disconnected -> scanning
Jul  4 16:02:57 elastomir NetworkManager[12446]: <info> caught signal 15, shutting down normally.

For some reason, NM doesn't seem to manage to set the ESSID.  My
understanding is that it tries to use some feature of wpa-supplicant
that isn't implemented for this particular card; I'm not sure whether
it's a bug in wpa-supplicant or one in NM, since NM worked fine on this
same laptop+card combination under Squeeze.

A further point of information: a local rebuild of the version of NM in
jessie/sid doesn't work either, with the following lines in syslog:

Jul  4 17:17:59 elastomir wpa_supplicant[1700]: nl80211: 'nl80211' generic netlink not found
Jul  4 17:17:59 elastomir wpa_supplicant[1700]: Failed to initialize driver 'nl80211'
Jul  4 17:17:59 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Jul  4 17:17:59 elastomir wpa_supplicant[1700]: ioctl[SIOCSIWENCODEEXT]: Invalid argument

Thanks,

Roland.

-- System Information:
Debian Release: 7.1
  APT prefers stable-updates
  APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: i386 (i686)

Kernel: Linux 3.2.0-4-686-pae (SMP w/1 CPU core)
Locale: LANG=fr_FR.UTF-8, LC_CTYPE=fr_FR.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages network-manager depends on:
ii  adduser                3.113+nmu3
ii  dbus                   1.6.8-1+deb7u1
ii  dpkg                   1.16.10
ii  isc-dhcp-client        4.2.2.dfsg.1-5+deb70u6
ii  libc6                  2.13-38
ii  libdbus-1-3            1.6.8-1+deb7u1
ii  libdbus-glib-1-2       0.100.2-1
ii  libgcrypt11            1.5.0-5
ii  libglib2.0-0           2.33.12+really2.32.4-5
ii  libgnutls26            2.12.20-7
ii  libgudev-1.0-0         175-7.2
ii  libnl-3-200            3.2.7-4
ii  libnl-genl-3-200       3.2.7-4
ii  libnl-route-3-200      3.2.7-4
ii  libnm-glib4            0.9.4.0-10
ii  libnm-util2            0.9.4.0-10
ii  libpolkit-gobject-1-0  0.105-3
ii  libuuid1               2.20.1-5.3
ii  lsb-base               4.1+Debian8+deb7u1
ii  udev                   175-7.2
ii  wpasupplicant          1.0-3+b1

Versions of packages network-manager recommends:
ii  crda          1.1.2-1
ii  dnsmasq-base  2.62-3+deb7u1
ii  iptables      1.4.14-3.1
ii  modemmanager  0.5.2.0-2
ii  policykit-1   0.105-3
ii  ppp           2.4.5-5.1+b1

Versions of packages network-manager suggests:
ii  avahi-autoipd  0.6.31-2

-- Configuration Files:
/etc/NetworkManager/NetworkManager.conf changed:
[main]
plugins=ifupdown,keyfile
no-auto-default=00:40:d0:45:76:70,2e:a6:20:e9:1b:fc,00:1f:11:01:04:e3,
[ifupdown]
managed=false

/etc/polkit-1/localauthority/10-vendor.d/org.freedesktop.NetworkManager.pkla [Errno 13] Permission non accordée: u'/etc/polkit-1/localauthority/10-vendor.d/org.freedesktop.NetworkManager.pkla'

-- no debconf information

-- 
Roland Mas

...sur un portable, quelque part dans le monde...
...on a laptop, somewhere in the world...



More information about the Pkg-utopia-maintainers mailing list