Hi Dan, hi all,
On 08/07/15 12:36, Dan Carpenter wrote:
The bug report says that it connects fine. Then in 10 minutes the
connection dies and reconnects. Is connecting an issue for you?
Oh, I was under the impression that the person who connects fine then
loses the connection sporadically had applied out-of-repository patches
-- guess you're right, that bug is a jumbled mess.
Here's what I see on my side. I'll try to be as thorough as I can.
I tried first with the Realtek driver (as in, the one available on my
github repo, that actually works), and scanned for access points using
NetworkManager, then manually with iwlist in order to rule out a problem
with NM. Then I repeated the same operations with the in-kernel driver.
I kept the logs of all cases (attached herein).
With the Realtek driver: the logs for when I load the module are in the
attached file, module-load-realtek.log. The driver itself isn't very
talkative, most of the logs are NetworkManager taking note of the device.
The logs of when I then tell NM to activate WiFi are in
nm-enable-realtek.log.
With that driver, NM scans and finds my access point, and autoconnects
to it.
I verified that after modprobing the driver, I can ifconfig the device
up, manually scan the neighborhood with 'iwlist wlan0 scan', and see the
access point.
Now, with the in-kernel driver. The logs for when I load it are in
module-load-inkernel.log. The logs are somewhat more verbose, though not
that much. I see nothing in there that would explain the problems.
When I then fire up the WiFi from NetworkManager, the logs
(nm-enable-inkernel.log) are mostly identical up until the point where
the interface state goes from ready to inactive. After this point,
however, NetworkManager doesn't see any access point, and stops there.
Once again, I used iwlist to scan for access points. Unlike with the
Realtek driver, this requires turning on the interface with the rfkill
command, but I don't think that's abnormal; I'm assuming this additional
level of control is a benefit of the in-kernel driver. With the
in-kernel driver, however, iwlist sees no access point ("No scan
results"). iw dev wlan0 scan doesn't show anything either.
There are no errors in the logs or on stderr. It's like the driver and
the wireless tools all think that everything is fine, they just fail to
see any access point, like the device just wasn't listening on its antenna.
Note: this is a slightly different from the behavior I was seeing way
back when I purchased that device and first discovered it was not
properly supported, somewhere around the time of kernel 3.10: back then,
the nearby access points WERE visible, but the connection would fail to
come up, like the device lost interest in listening to its antenna after
a few packets.
The TL;DR of that is "the device doesn't work with the official driver
and I have no useful information to provide as to why", which sucks.
Note: I also tried loading the module with the swenc=1 parameter, as
suggested in the bug report thread, but the result was identical.
As well: I dug out a 32 bits bootable image with the same kernel I'm
running (3.19.0). The symptoms are identical to what I see on my 64 bits
kernel. I don't know if that's the expected outcome.
At this point I can only see a few general approaches:
1/ Is it possible dump packets from the wireless interface (with
tcpdump, for instance) before the connection to the access point has
been established? Would such a dump help?
2/ Bisect the in-kernel module until I find the exact patch where things
stopped working. (Do I need to be running that exact kernel version or
can I bisect only the module?)
3/ Get the module maintainer the same device I own and hope they can
reproduce the issue. (Is that a thing that people do?)
Otherwise... I'm kind of stumped.
And Greg wrote:
Why? That's better than you will get from any other operating system,
where you don't have access to the developers who wrote the code, nor
even the company. You have a chance here, much more so than anywhere
else.
I may have misunderstood the spirit of your comment! I thought you meant
that a theoretically supported device staying unusable for upward of two
years was business as usual, which was /definitely/ a discomfiting
thought. :)
Cheers,
-- P.
kernel: rtl8192cu: Chip version 0x11
kernel: rtl8192cu: MAC address: ec:1a:XX:XX:XX:XX
kernel: rtl8192cu: Board Type 0
kernel: rtl_usb: rx_max_size 15360, rx_urb_num 8, in_ep 1
kernel: rtl8192cu: Loading firmware rtlwifi/rtl8192cufw_TMSC.bin
kernel: ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
kernel: usbcore: registered new interface driver rtl8192cu
NetworkManager[829]: <info> (wlan0): using nl80211 for WiFi device control
NetworkManager[829]: <info> (wlan0): driver supports Access Point (AP) mode
NetworkManager[829]: <info> (wlan0): new 802.11 WiFi device (driver: 'rtl8192cu' ifindex: 6)
NetworkManager[829]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/5
NetworkManager[829]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[829]: <info> (wlan0): preparing device
NetworkManager[829]: <info> devices added (path: /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/net/wlan0, iface: wlan0)
NetworkManager[829]: <info> device added (path: /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/net/wlan0, iface: wlan0): no ifupdown configuration found.
NetworkManager[829]: <info> rfkill0: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/ieee80211/phy0/rfkill0) (driver rtl8192cu)
NetworkManager[829]: <info> WiFi now disabled by radio killswitch
systemd[1]: Started ifup for wlan0.
systemd[1]: Starting ifup for wlan0...
systemd[1]: Created slice system-systemd\x2drfkill.slice.
systemd[1]: Starting system-systemd\x2drfkill.slice.
systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill0...
systemd[1]: Started Load/Save RF Kill Switch Status of rfkill0.
sh[27305]: Unknown interface wlan0
kernel: usbcore: registered new interface driver rtl8192cu
systemd[1]: Started ifup for wlan0.
systemd[1]: Starting ifup for wlan0...
NetworkManager[829]: <info> (wlan0): driver supports SSID scans (scan_capa 0x3F).
NetworkManager[829]: <info> (wlan0): using WEXT for WiFi device control
NetworkManager[829]: <info> (wlan0): new 802.11 WiFi device (driver: 'rtl8192cu' ifindex: 5)
NetworkManager[829]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/4
NetworkManager[829]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[829]: <info> (wlan0): preparing device
NetworkManager[829]: <error> [1436484185.506325] [platform/wifi/wifi-utils-wext.c:184] wifi_wext_set_powersave(): (wlan0): error setting powersave 0
NetworkManager[829]: <error> [1436484185.506469] [platform/wifi/wifi-utils-wext.c:160] wifi_wext_set_mode(): (wlan0): error setting mode 2
NetworkManager[829]: <info> devices added (path: /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/net/wlan0, iface: wlan0)
NetworkManager[829]: <info> device added (path: /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/net/wlan0, iface: wlan0): no ifupdown configuration found.
sh[26797]: Unknown interface wlan0
NetworkManager[829]: <info> WiFi hardware radio set enabled
kernel: rtl8192cu: MAC auto ON okay!
kernel: rtl8192cu: Tx queue select: 0x05
NetworkManager[829]: <info> WiFi now enabled by radio killswitch
wpa_supplicant[944]: dbus: wpa_dbus_get_object_properties: failed to get object properties: (none) none
wpa_supplicant[944]: dbus: Failed to construct signal
NetworkManager[829]: <warn> could not get interface properties: No readable properties in this interface.
NetworkManager[829]: <info> (wlan0): supplicant interface state: starting -> ready
NetworkManager[829]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
wpa_supplicant[944]: wlan0: CTRL-EVENT-SCAN-STARTED
NetworkManager[829]: <warn> could not get interface properties: No readable properties in this interface.
NetworkManager[829]: <info> (wlan0): supplicant interface state: ready -> inactive
NetworkManager[829]: <info> WiFi hardware radio set enabled
wpa_supplicant[944]: nl80211: Driver does not support authentication/association or connect commands
wpa_supplicant[944]: dbus: wpa_dbus_get_object_properties: failed to get object properties: (none) none
wpa_supplicant[944]: dbus: Failed to construct signal
NetworkManager[829]: <warn> could not get interface properties: No readable properties in this interface.
NetworkManager[829]: <info> (wlan0): supplicant interface state: starting -> ready
NetworkManager[829]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
NetworkManager[829]: <warn> could not get interface properties: No readable properties in this interface.
wpa_supplicant[944]: ioctl[SIOCSIWAP]: Operation not permitted
wpa_supplicant[944]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
wpa_supplicant[944]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
NetworkManager[829]: <info> (wlan0): supplicant interface state: ready -> inactive
NetworkManager[829]: <info> Auto-activating connection 'XXX'.
NetworkManager[829]: <info> Activation (wlan0) starting connection 'XXX'
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[829]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[829]: <info> NetworkManager state is now CONNECTING
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[829]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[829]: <info> Activation (wlan0/wireless): access point 'XXX' has security, but secrets are required.
NetworkManager[829]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[829]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[829]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[829]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[829]: <info> Activation (wlan0/wireless): connection 'XXX' has security, and secrets exist. No new secrets needed.
NetworkManager[829]: <error> [1436484214.046450] [platform/wifi/wifi-utils-wext.c:184] wifi_wext_set_powersave(): (wlan0): error setting powersave 1
NetworkManager[829]: <info> Config: added 'ssid' value 'XXX'
NetworkManager[829]: <info> Config: added 'scan_ssid' value '1'
NetworkManager[829]: <info> Config: added 'bssid' value '00:24:XX:XX:XX:XX'
NetworkManager[829]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
NetworkManager[829]: <info> Config: added 'psk' value '<omitted>'
NetworkManager[829]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[829]: <info> Config: set interface ap_scan to 1
wpa_supplicant[944]: wlan0: Trying to associate with 00:24:XX:XX:XX:XX (SSID='XXX' freq=2467 MHz)
wpa_supplicant[944]: wlan0: Association request to the driver failed
NetworkManager[829]: <info> (wlan0): supplicant interface state: inactive -> associating
wpa_supplicant[944]: wlan0: Associated with 00:24:XX:XX:XX:XX
NetworkManager[829]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
wpa_supplicant[944]: wlan0: WPA: Key negotiation completed with 00:24:XX:XX:XX:XX [PTK=CCMP GTK=CCMP]
wpa_supplicant[944]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:24:XX:XX:XX:XX completed [id=0 id_str=]
NetworkManager[829]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
NetworkManager[829]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'XXX'.
NetworkManager[829]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[829]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[829]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[829]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[829]: <info> dhclient started with pid 26808
NetworkManager[829]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[829]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
dhclient[26808]: DHCPREQUEST of 192.168.0.100 on wlan0 to 255.255.255.255 port 67 (xid=0x3a9df9b8)
dhclient[26808]: DHCPACK of 192.168.0.100 from 192.168.0.254
NetworkManager[829]: <info> (wlan0): DHCPv4 state changed preinit -> reboot
NetworkManager[829]: <info> address 192.168.0.100
NetworkManager[829]: <info> plen 24 (255.255.255.0)
NetworkManager[829]: <info> gateway 192.168.0.254
NetworkManager[829]: <info> server identifier 192.168.0.254
NetworkManager[829]: <info> lease time 43200
NetworkManager[829]: <info> nameserver '5.135.X.X'
NetworkManager[829]: <info> nameserver '192.168.0.254'
NetworkManager[829]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
NetworkManager[829]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) started...
avahi-daemon[848]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.100.
NetworkManager[829]: <info> (wlan0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
dhclient[26808]: bound to 192.168.0.100 -- renewal in 16254 seconds.
avahi-daemon[848]: New relevant interface wlan0.IPv4 for mDNS.
NetworkManager[829]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) complete.
_______________________________________________
devel mailing list
devel@xxxxxxxxxxxxxxxxxxxxxx
http://driverdev.linuxdriverproject.org/mailman/listinfo/driverdev-devel
