GNOME.org
 

Re: Ad-Hoc network creation took too long, failing activation

On Thu, 2014-10-09 at 00:24 +0200, poma wrote:

On 08.10.2014 20:31, Dan Williams wrote:

On Wed, 2014-10-08 at 00:10 +0200, poma wrote:

Starting Network Manager...
<info> NetworkManager (version 0.9.10.0-5.git20140704.fc21) is starting...
<info> WEXT support is enabled
<info> WiFi hardware radio set enabled
<info> Loaded device plugin: /usr/lib/NetworkManager/libnm-device-plugin-wifi.so
<info> WiFi enabled by radio killswitch; enabled by state file
<info> Networking is enabled by state file
Started Network Manager.
<info> (ra0): driver does not support SSID scans (scan_capa 0x00).
<info> (ra0): using WEXT for WiFi device control
<info> (ra0): new 802.11 WiFi device (driver: 'usb' ifindex: 5)
<info> (ra0): exported as /org/freedesktop/NetworkManager/Devices/4
<info> (ra0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
<info> (ra0): preparing device
<warn> (ra0): error 100 getting card mode
<error> [1412709645.317223] [platform/wifi/wifi-utils-wext.c:160] wifi_wext_set_mode(): (ra0): error 
setting mode 2


Ugh, looks like you're using WEXT, which is historically quite
problematic because different drivers expected different sequences of
WEXT requests.  Any driver that uses WEXT and is not upstream is
automatically suspect, unfortunately...


<info> wpa_supplicant started
<info> (ra0) supports 1 scan SSIDs
<info> (ra0): supplicant interface state: starting -> ready
<info> (ra0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
<info> (ra0): supplicant interface state: ready -> disconnected
<info> (ra0) supports 1 scan SSIDs
<info> startup complete
<info> (ra0): supplicant interface state: disconnected -> inactive
...
<info> (ra0): disconnecting for new activation request.
<info> (ra0): device state change: activated -> deactivating (reason 'none') [100 110 0]
<info> NetworkManager state is now DISCONNECTING
<info> (ra0): device state change: deactivating -> disconnected (reason 'none') [110 30 0]
<info> (ra0): deactivating device (reason 'none') [0]
<info> (ra0): canceled DHCP transaction, DHCP client pid 1144
<info> NetworkManager state is now DISCONNECTED
<info> Activation (ra0) starting connection 'bla'
<info> Activation (ra0) Stage 1 of 5 (Device Prepare) scheduled...
<warn> Connection disconnected (reason -3)
<info> (ra0): supplicant interface state: completed -> disconnected
<info> Activation (ra0) Stage 1 of 5 (Device Prepare) started...
<info> (ra0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
<info> NetworkManager state is now CONNECTING
<info> Activation (ra0) Stage 2 of 5 (Device Configure) scheduled...
<info> Activation (ra0) Stage 1 of 5 (Device Prepare) complete.
<info> Activation (ra0) Stage 2 of 5 (Device Configure) starting...
<info> (ra0): device state change: prepare -> config (reason 'none') [40 50 0]
<info> Activation (ra0/wireless): connection 'bla' has security, and secrets exist.  No new secrets 
needed.
<info> Config: added 'ssid' value 'bla'
<info> Config: added 'mode' value '1'
<info> Config: added 'frequency' value '2412'
<info> Config: added 'key_mgmt' value 'NONE'
<info> Config: added 'auth_alg' value 'OPEN'
<info> Config: added 'wep_key0' value '<omitted>'
<info> Config: added 'wep_tx_keyidx' value '0'
<info> Activation (ra0) Stage 2 of 5 (Device Configure) complete.
<info> Config: set interface ap_scan to 2
<info> (ra0): supplicant interface state: disconnected -> associating
<warn> Activation (ra0/wireless): Ad-Hoc network creation took too long, failing activation.


The driver did not emit the SIOCGIWAP event, indicating that it had
successfully completed Ad-Hoc AP setup.  This is a driver bug.


<info> (ra0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
<info> NetworkManager state is now DISCONNECTED
<warn> Activation (ra0) failed for connection 'bla'
<warn> Connection disconnected (reason -3)
<info> (ra0): supplicant interface state: associating -> disconnected
<info> (ra0): device state change: failed -> disconnected (reason 'none') [120 30 0]
<info> (ra0): deactivating device (reason 'none') [0]
<warn> (ra0): error 100 getting card mode
<error> [1412717534.522258] [platform/wifi/wifi-utils-wext.c:160] wifi_wext_set_mode(): (ra0): error 
setting mode 2


IBSS works via Wicd although not reliable.
BTW AP/WPA2, is it possible at all?


NM supports AP mode if wpa_supplicant supports it on the device, but
given the information you've provided here, the driver looks very
fragile and I wouldn't expect it to work.  WPA2 may be possible, but
again the driver is quite suspect.

The driver is just bad, I'm afraid...

Dan



Thanks, 
whether the same(Ad-Hoc/IBSS & WEXT == unsupported) applies to this module also


Could you do the following to get supplicant debug logs in this case?
They can be enabled by dbus, but it's sometimes easier to just:

1) mv /usr/sbin/wpa_supplicant /
2) killall -TERM wpa_supplicant
3) /wpa_supplicant -dddtu  (and redirect to your favorite location)
4) retry the connection
5) mail/attach the supplicant output

Dan


- dmesg:
usb 2-3: new high-speed USB device number 3 using ehci-pci
usb 2-3: New USB device found, idVendor=0bda, idProduct=8171
usb 2-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 2-3: Product: RTL8188S WLAN Adapter 
usb 2-3: Manufacturer: Manufacturer Realtek 
usb 2-3: SerialNumber: 00e04c000001
r8712u: module is from the staging directory, the quality is unknown, you have been warned.
r8712u: Staging version
r8712u: register rtl8712_netdev_ops to netdev_ops
usb 2-3: r8712u: USB_SPEED_HIGH with 4 endpoints
usb 2-3: r8712u: Boot from EFUSE: Autoload OK
usb 2-3: r8712u: CustomerID = 0x0000
usb 2-3: r8712u: MAC Address from efuse = [...]
usb 2-3: r8712u: Loading firmware from "rtlwifi/rtl8712u.bin"
usbcore: registered new interface driver r8712u
r8712u 2-3:1.0 wlp0s4f1u3: renamed from wlan0
systemd-udevd[363]: renamed network interface wlan0 to wlp0s4f1u3
r8712u 2-3:1.0 wlp0s4f1u3: 1 RCR=0x153f00e
r8712u 2-3:1.0 wlp0s4f1u3: 2 RCR=0x553f00e
IPv6: ADDRCONF(NETDEV_UP): wlp0s4f1u3: link is not ready
...


- /etc/NetworkManager/system-connections/IBSS:
[connection]
id=IBSS
uuid=...
type=wifi
autoconnect=false
zone=public

[wifi]
ssid=IBSS
mode=adhoc
band=bg
channel=1
mac-address=[...]
security=802-11-wireless-security

[ipv6]
method=ignore
ip6-privacy=0

[ipv4]
method=shared


- journalctl:
Starting Network Manager...
<info> NetworkManager (version 0.9.10.0-5.git20140704.fc21) is starting...
<info> Read config: /etc/NetworkManager/NetworkManager.conf and conf.d: keyfile-plugin.conf
<info> WEXT support is enabled
<info> Loaded plugin keyfile: (c) 2007 - 2013 Red Hat, Inc.  To report bugs please use the NetworkManager 
mailing list.
<info> new connection /etc/NetworkManager/system-connections/IBSS
<info> new connection /etc/NetworkManager/system-connections/enp3s0
<info> new connection /etc/NetworkManager/system-connections/MBB
<info> monitoring kernel firmware directory '/lib/firmware'.
<info> WiFi hardware radio set enabled
<info> WWAN hardware radio set enabled
<info> Loaded device plugin: /usr/lib/NetworkManager/libnm-device-plugin-wifi.so
<info> Loaded device plugin: /usr/lib/NetworkManager/libnm-device-plugin-wwan.so
<info> WiFi enabled by radio killswitch; enabled by state file
<info> WWAN enabled by radio killswitch; enabled by state file
<info> WiMAX enabled by radio killswitch; enabled by state file
<info> Networking is enabled by state file
Started Network Manager.
<info> (lo): link connected
<info> (lo): carrier is ON
<info> (lo): new Generic device (driver: 'unknown' ifindex: 1)
<info> (lo): exported as /org/freedesktop/NetworkManager/Devices/0
<info> (enp3s0): carrier is OFF
<info> (enp3s0): new Ethernet device (driver: 'r8169' ifindex: 4)
<info> (enp3s0): exported as /org/freedesktop/NetworkManager/Devices/3
<info> (enp3s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
<info> (enp3s0): preparing device
<info> (wlp0s4f1u3): driver does not support SSID scans (scan_capa 0x00).
<info> (wlp0s4f1u3): using WEXT for WiFi device control
<info> (wlp0s4f1u3): new 802.11 WiFi device (driver: 'r8712u' ifindex: 5)
<info> (wlp0s4f1u3): exported as /org/freedesktop/NetworkManager/Devices/4
<info> (wlp0s4f1u3): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
<info> (wlp0s4f1u3): preparing device
<info> ModemManager available in the bus
<info> wpa_supplicant started
<info> (enp3s0): link connected
<info> (enp3s0): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
<info> Auto-activating connection 'enp3s0'.
<info> Activation (enp3s0) starting connection 'enp3s0'
<info> Activation (enp3s0) Stage 1 of 5 (Device Prepare) scheduled...
<info> Activation (enp3s0) Stage 1 of 5 (Device Prepare) started...
<info> (enp3s0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
<info> NetworkManager state is now CONNECTING
<info> Activation (enp3s0) Stage 2 of 5 (Device Configure) scheduled...
<info> Activation (enp3s0) Stage 1 of 5 (Device Prepare) complete.
<info> Activation (enp3s0) Stage 2 of 5 (Device Configure) starting...
<info> (enp3s0): device state change: prepare -> config (reason 'none') [40 50 0]
<info> Activation (enp3s0) Stage 2 of 5 (Device Configure) successful.
<info> Activation (enp3s0) Stage 2 of 5 (Device Configure) complete.
<info> (wlp0s4f1u3) supports 1 scan SSIDs
<info> (wlp0s4f1u3): supplicant interface state: starting -> ready
<info> (wlp0s4f1u3): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 
30 42]
<info> (wlp0s4f1u3): supplicant interface state: ready -> disconnected
<info> (wlp0s4f1u3) supports 1 scan SSIDs
<info> Activation (enp3s0) Stage 3 of 5 (IP Configure Start) scheduled.
<info> Activation (enp3s0) Stage 3 of 5 (IP Configure Start) started...
<info> (enp3s0): device state change: config -> ip-config (reason 'none') [50 70 0]
<info> Activation (enp3s0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
<info> Activation (enp3s0) Stage 3 of 5 (IP Configure Start) complete.
<info> Activation (enp3s0) Stage 5 of 5 (IPv4 Commit) started...
<info> (enp3s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
<info> Activation (enp3s0) Stage 5 of 5 (IPv4 Commit) complete.
<info> (enp3s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
<info> (enp3s0): device state change: secondaries -> activated (reason 'none') [90 100 0]
<info> NetworkManager state is now CONNECTED_LOCAL
<info> NetworkManager state is now CONNECTED_GLOBAL
<info> Policy set 'enp3s0' (enp3s0) as default for IPv4 routing and DNS.
<info> Activation (enp3s0) successful, device activated.
<info> startup complete
<info> (wlp0s4f1u3): supplicant interface state: disconnected -> inactive

$ nmcli connection up IBSS

<info> Activation (wlp0s4f1u3) starting connection 'IBSS'
<info> Activation (wlp0s4f1u3) Stage 1 of 5 (Device Prepare) scheduled...
<info> Activation (wlp0s4f1u3) Stage 1 of 5 (Device Prepare) started...
<info> (wlp0s4f1u3): device state change: disconnected -> prepare (reason 'none') [30 40 0]
<info> Activation (wlp0s4f1u3) Stage 2 of 5 (Device Configure) scheduled...
<info> Activation (wlp0s4f1u3) Stage 1 of 5 (Device Prepare) complete.
<info> Activation (wlp0s4f1u3) Stage 2 of 5 (Device Configure) starting...
<info> (wlp0s4f1u3): device state change: prepare -> config (reason 'none') [40 50 0]
<info> Activation (wlp0s4f1u3/wireless): connection 'IBSS' requires no security.  No secrets needed.
<info> Config: added 'ssid' value 'IBSS'
<info> Config: added 'mode' value '1'
<info> Config: added 'frequency' value '2412'
<info> Config: added 'freq_list' value 
'2412,2417,2422,2427,2432,2437,2442,2447,2452,2457,2462,2467,2472,2484'
<info> Config: added 'key_mgmt' value 'NONE'
<info> Activation (wlp0s4f1u3) Stage 2 of 5 (Device Configure) complete.
<info> Config: set interface ap_scan to 2
<info> (wlp0s4f1u3): supplicant interface state: inactive -> associating
<warn> Activation (wlp0s4f1u3/wireless): Ad-Hoc network creation took too long, failing activation.
<info> (wlp0s4f1u3): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
<warn> Activation (wlp0s4f1u3) failed for connection 'IBSS'
<info> (wlp0s4f1u3): device state change: failed -> disconnected (reason 'none') [120 30 0]
<info> (wlp0s4f1u3): deactivating device (reason 'none') [0]
<warn> Connection disconnected (reason -3)
<info> (wlp0s4f1u3): supplicant interface state: associating -> disconnected
<warn> Couldn't disconnect supplicant interface: This interface is not connected.
<info> (wlp0s4f1u3): supplicant interface state: disconnected -> disabled


$ rpm -q wpa_supplicant 
wpa_supplicant-2.0-11.fc21.i686
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]