After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 764803 - usb ath9k wifi asigned default wired connection at boot
usb ath9k wifi asigned default wired connection at boot
Status: RESOLVED FIXED
Product: NetworkManager
Classification: Platform
Component: Wi-Fi
1.1.x
Other Linux
: Normal normal
: ---
Assigned To: NetworkManager maintainer(s)
NetworkManager maintainer(s)
: 765123 765839 766192 766786 767243 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2016-04-08 19:52 UTC by Jason Woofenden
Modified: 2017-05-30 17:22 UTC
See Also:
GNOME target: ---
GNOME version: ---

Attachments
[PATCH] platform: add logs to debug link type matching (4.49 KB, patch)
2016-04-21 11:46 UTC, Beniamino Galvani 		none Details | Review
[v2 for master] 0001-platform-add-logs-to-debug-link-type-matching.patch (4.58 KB, patch)
2016-04-21 13:27 UTC, Thomas Haller 		none Details | Review
NM trace log including working after restart (224.14 KB, text/x-log)
2016-04-24 00:24 UTC, Tatsuyuki Ishi 		  Details
[PATCH] platform: reuse cached type only for udev-initialized links (2.19 KB, patch)
2016-04-24 19:24 UTC, Beniamino Galvani 		none Details | Review
log with NM thinks wifi is wired usb (149.27 KB, text/plain)
2016-07-24 03:50 UTC, slesru 		  Details

Description Jason Woofenden 2016-04-08 19:52:03 UTC 
Hi all,

I posted this first to https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=820352 and they asked me to report it here, since they don't have a wifi card that can reproduce my issue.

I'm pasting my full report below, plus additional info from udevadmin that a debian maintainer suggested I add.

Package: network-manager
Version: 1.1.93-1
Severity: important

Dear Maintainer,

Every time I boot linux (2-ish times per day) NetworkManager won't
connect to my wifi, because it thinks my wifi card is an ethernet
device.

I try this:

	nmcli d wifi list

And it outputs nothing.

However, this has lots of output:

	iwlist scan

So it appears that the kernel knows it's a wifi card.

This command:

	journalctl | grep "ath9k\|wlx00"

produces:

	Apr 05 12:42:10 compy kernel: usb 5-3: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
	Apr 05 12:42:10 compy kernel: usbcore: registered new interface driver ath9k_htc
	Apr 05 12:42:10 compy kernel: usb 5-3: firmware: direct-loading firmware ath9k_htc/htc_9271-1.4.0.fw
	Apr 05 12:42:10 compy kernel: usb 5-3: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
	Apr 05 12:42:11 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: HTC initialized with 33 credits
	Apr 05 12:42:11 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: FW Version: 1.4
	Apr 05 12:42:11 compy kernel: ath9k_htc 5-3:1.0: FW RMW support: On
	Apr 05 12:42:11 compy kernel: ath9k_htc 5-3:1.0 wlx00c0ca81fdaa: renamed from wlan0
	Apr 05 12:42:11 compy NetworkManager[665]: <info>  [1459874531.9945] rfkill0: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/ieee80211/phy0/rfkill0) (driver ath9k_htc)
	Apr 05 12:42:11 compy NetworkManager[665]: <info>  [1459874531.9976] devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
	Apr 05 12:42:11 compy NetworkManager[665]: <info>  [1459874531.9979] device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa): no ifupdown configuration found.
	Apr 05 12:42:12 compy NetworkManager[665]: <info>  [1459874532.0563] manager: (wlx00c0ca81fdaa): new Ethernet device (/org/freedesktop/NetworkManager/Devices/3)
	Apr 05 12:42:12 compy NetworkManager[665]: <info>  [1459874532.0610] settings: (wlx00c0ca81fdaa): created default wired connection 'Wired connection 2'
	Apr 05 12:42:12 compy NetworkManager[665]: <info>  [1459874532.0624] device (wlx00c0ca81fdaa): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
	Apr 05 12:42:12 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
	Apr 05 12:42:12 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready


Then, I unplug my wifi adapter (usb) and plug it back in. Now I get
this additional output from ``journalctl | grep "ath9k\|wlx00"``

	Apr 05 12:43:28 compy NetworkManager[665]: <info>  [1459874608.2591] device (wlx00c0ca81fdaa): state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
	Apr 05 12:43:28 compy NetworkManager[665]: <warn>  [1459874608.2659] device (wlx00c0ca81fdaa): failed to disable userspace IPv6LL address handling
	Apr 05 12:43:28 compy NetworkManager[665]: <info>  [1459874608.2667] devices removed (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
	Apr 05 12:43:28 compy kernel: usb 5-3: ath9k_htc: USB layer deinitialized
	Apr 05 12:43:32 compy kernel: usb 5-3: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
	Apr 05 12:43:32 compy kernel: usb 5-3: firmware: direct-loading firmware ath9k_htc/htc_9271-1.4.0.fw
	Apr 05 12:43:32 compy kernel: usb 5-3: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
	Apr 05 12:43:33 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: HTC initialized with 33 credits
	Apr 05 12:43:33 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: FW Version: 1.4
	Apr 05 12:43:33 compy kernel: ath9k_htc 5-3:1.0: FW RMW support: On
	Apr 05 12:43:33 compy kernel: ath9k_htc 5-3:1.0 wlx00c0ca81fdaa: renamed from wlan0
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.5156] rfkill1: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/ieee80211/phy1/rfkill1) (driver ath9k_htc)
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.5213] device (wlan0): interface index 5 renamed iface from 'wlan0' to 'wlx00c0ca81fdaa'
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.5265] devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.5265] device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa): no ifupdown configuration found.
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.5266] device (wlx00c0ca81fdaa): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
	Apr 05 12:43:33 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
	Apr 05 12:43:33 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.7440] sup-iface[0x9aeea88,wlx00c0ca81fdaa]: supports 4 scan SSIDs
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.7455] device (wlx00c0ca81fdaa): supplicant interface state: starting -> ready
	Apr 05 12:43:33 compy NetworkManager[665]: <info>  [1459874613.7456] device (wlx00c0ca81fdaa): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
	Apr 05 12:43:33 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
	Apr 05 12:43:34 compy NetworkManager[665]: <info>  [1459874614.9209] device (wlx00c0ca81fdaa): supplicant interface state: ready -> inactive
	Apr 05 12:43:34 compy NetworkManager[665]: <info>  [1459874614.9346] device (wlx00c0ca81fdaa): Activation: starting connection [...]
[...]

And it connects to my wifi network automatically, and works
beautifully until next time I start linux up.

The log is from a couple days ago because I've been waiting to see
if this problem was consistent. It happens exactly like this every
time for me.

Several days ago, I had a similar problem, but it was intermittent,
and I could fix it with ``/etc/init.d/network-manager restart``.

Now if I run that, it still won't connect.


My wifi device is:

	Wireless N USB GNU/Linux Adapter
	Atheros AR9271
	Model: TPE-N150USBL

purchased from ThinkPenguin

It gets great reception, is very reliable, and works flawlessly
(including auto-connect on boot) under Windows.


Please let me know if there's further experiments, information
gathering, etc. that I can do that would help diagnose this problem.

Thank you,   - Jason


-- System Information:
Debian Release: stretch/sid
  APT prefers unstable
  APT policy: (500, 'unstable')
Architecture: i386 (i686)

Kernel: Linux 4.4.0-1-686-pae (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) (ignored: LC_ALL set to en_US.UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages network-manager depends on:
ii  adduser                3.114
ii  dbus                   1.10.8-1
ii  init-system-helpers    1.29
ii  isc-dhcp-client        4.3.3-9+b1
ii  libbluetooth3          5.36-1
ii  libc6                  2.22-5
ii  libglib2.0-0           2.48.0-1
ii  libgnutls30            3.4.10-4
ii  libgudev-1.0-0         230-3
ii  libmm-glib0            1.4.14-1
ii  libndp0                1.4-2
ii  libnewt0.52            0.52.18-3
ii  libnl-3-200            3.2.27-1
ii  libnm0                 1.1.93-1
ii  libpam-systemd         229-3
ii  libpolkit-agent-1-0    0.105-14.1
ii  libpolkit-gobject-1-0  0.105-14.1
ii  libreadline6           6.3-8+b4
ii  libsoup2.4-1           2.52.2-1
ii  libsystemd0            229-3
ii  libteamdctl0           1.23-1
ii  libuuid1               2.27.1-6
ii  lsb-base               9.20160110
ii  policykit-1            0.105-14.1
ii  udev                   229-3
ii  wpasupplicant          2.3-2.3

Versions of packages network-manager recommends:
ii  crda            3.13-1+b1
ii  dnsmasq-base    2.75-1
ii  iptables        1.6.0-2
pn  iputils-arping  <none>
ii  modemmanager    1.4.14-1
ii  ppp             2.4.7-1+2

Versions of packages network-manager suggests:
pn  libteam-utils  <none>

-- no debconf information

udevadm info /sys/class/net/wlx00c0ca81fdaa produced this output:

	P: /devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa
	E: DEVPATH=/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa
	E: DEVTYPE=wlan
	E: ID_BUS=usb
	E: ID_MM_CANDIDATE=1
	E: ID_MODEL=UB91C
	E: ID_MODEL_ENC=UB91C
	E: ID_MODEL_FROM_DATABASE=AR9271 802.11n
	E: ID_MODEL_ID=9271
	E: ID_NET_DRIVER=ath9k_htc
	E: ID_NET_LINK_FILE=/lib/systemd/network/90-mac-for-usb.link
	E: ID_NET_NAME=wlx00c0ca81fdaa
	E: ID_NET_NAME_MAC=wlx00c0ca81fdaa
	E: ID_NET_NAME_PATH=wlp0s29f7u3
	E: ID_OUI_FROM_DATABASE=ALFA, INC.
	E: ID_PATH=pci-0000:00:1d.7-usb-0:3:1.0
	E: ID_PATH_TAG=pci-0000_00_1d_7-usb-0_3_1_0
	E: ID_REVISION=0108
	E: ID_SERIAL=ATHEROS_UB91C_12345
	E: ID_SERIAL_SHORT=12345
	E: ID_TYPE=generic
	E: ID_USB_CLASS_FROM_DATABASE=Vendor Specific Class
	E: ID_USB_DRIVER=ath9k_htc
	E: ID_USB_INTERFACES=:ff0000:
	E: ID_USB_INTERFACE_NUM=00
	E: ID_USB_PROTOCOL_FROM_DATABASE=Vendor Specific Protocol
	E: ID_USB_SUBCLASS_FROM_DATABASE=Vendor Specific Subclass
	E: ID_VENDOR=ATHEROS
	E: ID_VENDOR_ENC=ATHEROS
	E: ID_VENDOR_FROM_DATABASE=Atheros Communications, Inc.
	E: ID_VENDOR_ID=0cf3
	E: IFINDEX=3
	E: INTERFACE=wlx00c0ca81fdaa
	E: SUBSYSTEM=net
	E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/wlx00c0ca81fdaa /sys/subsystem/net/devices/wlx00c0ca81fdaa
	E: TAGS=:systemd:
	E: USEC_INITIALIZED=22940208

after a cold boot (when NM was still thinking it was not a wireless card). After unplugging, and reconnecting the card (and NM connecting correctly, as described above), the output of that udevadm command was the same, except IFINDEX=5 and USEC_INITIALIZED was changed.
Comment 1 Beniamino Galvani 2016-04-11 07:49:20 UTC 
Hi,
thanks for the detailed report! Can you please enable debug logging and attach the relevant lines? To enable debug, set level=TRACE in the [logging] section of /etc/NetworkManager/NetworkManager.conf and restart the service.
Comment 2 Jason Woofenden 2016-04-11 16:05:43 UTC 
Hi,

Thanks for your reply.

I set my logging level to TRACE.

Last night and this morning when I booted this bug didn't happen. So perhaps this was fixed already, and the change just made it to debian sid.

I'm going to monitor this closely over the next few days. By the end of the week I'll write back here with a trace level log, or a report that I can no longer reproduce this, and presume it fixed.
Comment 3 Dan Williams 2016-04-19 15:45:20 UTC 
When the device is *not* detected as wifi by NM, could you run the following commands in a terminal? (replace <interface name> with the wifi device's interface name):

cat /sys/class/net/<interface name>/uevent
ls -alp /sys/class/net/<interface name>/phy80211
Comment 4 Jason Woofenden 2016-04-19 19:41:08 UTC 
Update: Now this bug is intermittent for me (maybe 60-70% of the time it bugs).

Sorry for the delay, I didn't reboot for a while because tax prep.

@Dan I'll run your commands next buggy boot.

Below is my log from this boot. It bugged as described above, then I unplugged and re-plugged the usb wifi device, and then it worked. Sorry I didn't wait longer so the time gap is more obvious. There's a bit of a time gap from seconds 39-53 which I assume is when I unplugged and re-plugged.

As usual, after plugging it back in, it connected very quickly.

Output of journalctl | grep -i "ath9k\|wlx00\|\<nm\>\|network.?manager" | grep -v 'tun[0-9]'

Apr 19 15:14:37 compy kernel: usb 5-3: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
Apr 19 15:14:37 compy kernel: usbcore: registered new interface driver ath9k_htc
Apr 19 15:14:37 compy kernel: usb 5-3: firmware: direct-loading firmware ath9k_htc/htc_9271-1.4.0.fw
Apr 19 15:14:38 compy kernel: usb 5-3: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
Apr 19 15:14:38 compy dbus[592]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr 19 15:14:38 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: HTC initialized with 33 credits
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname': new request (1 scripts)
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname': environment: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname': start running ordered scripts...
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname', "/etc/NetworkManager/dispatcher.d/01ifupdown": run script
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname', "/etc/NetworkManager/dispatcher.d/01ifupdown": complete
Apr 19 15:14:38 compy nm-dispatcher[999]: req:1 'hostname': completed (1 scripts)
Apr 19 15:14:38 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: FW Version: 1.4
Apr 19 15:14:38 compy kernel: ath9k_htc 5-3:1.0: FW RMW support: On
Apr 19 15:14:38 compy kernel: ath9k_htc 5-3:1.0 wlx00c0ca81fdaa: renamed from wlan0
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.2408] platform-linux: event-notification: NEWLINK, seq 0: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? not-init addrgenmode eui64 addr 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.2408] platform: signal: link changed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? not-init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.2648] rfkill0: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/ieee80211/phy0/rfkill0) (driver ath9k_htc)
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.2652] devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.2652] device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa): no ifupdown configuration found.
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.2658] platform-linux: UDEV event: action 'add' subsys 'net' device 'wlx00c0ca81fdaa' (4); seqnum=1695
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.2658] platform-linux: udev-add[wlx00c0ca81fdaa,4]: device added
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.2659] platform: signal: link changed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.2703] platform-linux: UDEV event: action 'move' subsys 'net' device 'wlx00c0ca81fdaa' (4); seqnum=1703
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.2703] platform-linux: udev-add[wlx00c0ca81fdaa,4]: device added
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.2705] platform: signal: link changed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3060] device[0x95306f8] (wlx00c0ca81fdaa): constructed (NMDeviceEthernet)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3061] device[0x95306f8] (wlx00c0ca81fdaa): start setup of NMDeviceEthernet, kernel ifindex 4
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3061] platform-linux: error reading /sys/class/net/wlx00c0ca81fdaa/phys_port_id: Failed to read from file '/sys/class/net/wlx00c0ca81fdaa/phys_port_id': Operation not supported
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3062] platform-linux: sysctl: reading '/sys/class/net/wlx00c0ca81fdaa/dev_id': '0x0'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3062] device[0x95306f8] (wlx00c0ca81fdaa): hardware address now 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3062] device[0x95306f8] (wlx00c0ca81fdaa): read initial MAC address 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3063] device[0x95306f8] (wlx00c0ca81fdaa): read permanent MAC address 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3063] device[0x95306f8] (wlx00c0ca81fdaa): carrier is OFF
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3063] device[0x95306f8] (wlx00c0ca81fdaa): unmanaged: flags set to [platform-init,!loopback=0x10/0x18/unmanaged/unrealized, set-managed [loopback=0x8])
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3063] device[0x95306f8] (wlx00c0ca81fdaa): unmanaged: flags set to [!loopback,!platform-init=0x0/0x18/managed/unrealized, set-managed [platform-init=0x10])
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3063] device[0x95306f8] (wlx00c0ca81fdaa): unmanaged: flags set to [!loopback,!platform-init,!user-settings=0x0/0x58/managed/unrealized, set-managed [user-settings=0x40])
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3064] device[0x95306f8] (wlx00c0ca81fdaa): unmanaged: flags set to [!sleeping,!loopback,!platform-init,!user-settings=0x0/0x59/managed/unrealized, set-managed [sleeping=0x1])
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.3091] manager: (wlx00c0ca81fdaa): new Ethernet device (/org/freedesktop/NetworkManager/Devices/3)
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.3168] settings: (wlx00c0ca81fdaa): created default wired connection 'Wired connection 2'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3186] device[0x95306f8] (wlx00c0ca81fdaa): set IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/4)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3217] device[0x95306f8] (wlx00c0ca81fdaa): set IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/4)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3218] device[0x95306f8] (wlx00c0ca81fdaa): device has no existing configuration
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3219] manager: (wlx00c0ca81fdaa): can't assume; no connection
Apr 19 15:14:39 compy NetworkManager[678]: <info>  [1461093279.3219] device (wlx00c0ca81fdaa): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3219] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra': '1'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3220] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_defrtr': '1'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3220] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_pinfo': '1'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3220] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_rtr_pref': '1'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3220] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6': '0'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3221] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/hop_limit': '64'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3221] platform-linux: sysctl: reading '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr': '0'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3221] device[0x95306f8] (wlx00c0ca81fdaa): will enable userland IPv6LL
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.3222] platform-linux: event-notification: NEWLINK, seq 13: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3223] platform: signal: link changed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3223] device[0x95306f8] (wlx00c0ca81fdaa): queued link change for ifindex 4
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3224] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '1' (current value is '0')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3224] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '0' (current value is '1')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3225] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_defrtr' to '0' (current value is '1')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3225] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_pinfo' to '0' (current value is '1')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3225] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_rtr_pref' to '0' (current value is '1')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3226] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr' to '0' (current value is identical)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3226] device[0x95306f8] (wlx00c0ca81fdaa): bringing up device
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.3226] platform: link: setting up 'wlx00c0ca81fdaa' (4)
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.5292] platform-linux: event-notification: NEWLINK, seq 0: 4: wlx00c0ca81fdaa <UP;broadcast,multicast,up,running> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5293] platform: signal: link changed: 4: wlx00c0ca81fdaa <UP;broadcast,multicast,up,running> mtu 1500 arp 1 ethernet? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.5293] platform-linux: event-notification: NEWLINK, seq 15: 4: wlx00c0ca81fdaa <UP;broadcast,multicast,up,running> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5294] device[0x95306f8] (wlx00c0ca81fdaa): add_pending_action (1): 'carrier wait'
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5294] device[0x95306f8] (wlx00c0ca81fdaa): preparing device
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5294] device[0x95306f8] (wlx00c0ca81fdaa): clearing queued IP4 config change
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5295] device[0x95306f8] (wlx00c0ca81fdaa): clearing queued IP6 config change
Apr 19 15:14:39 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5295] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (1): 'dhcp6' not pending (expected)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5295] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (1): 'autoconf6' not pending (expected)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5295] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra' to '0' (current value is '1')
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5297] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr' to '0' (current value is identical)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5297] device[0x95306f8] (wlx00c0ca81fdaa): no MAC address change needed
Apr 19 15:14:39 compy NetworkManager[678]: <trace> [1461093279.5298] platform-linux: event-notification: NEWLINK, seq 0: 4: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5298] platform: signal: link changed: 4: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 ethernet? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5299] default-route: entry[0/dev:0x95306f8:wlx00c0ca81fdaa:0:+sync]: record:add    0.0.0.0/0 via 0.0.0.0 dev 4 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5299] default-route: entry[0/dev:0x95306f8:wlx00c0ca81fdaa:0:+sync]: record:add    ::/0 via :: dev 4 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5299] default-route: entry[0/dev:0x95306f8:wlx00c0ca81fdaa:0:+sync]: record:remove 0.0.0.0/0 via 0.0.0.0 dev 4 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5299] default-route: entry[0/dev:0x95306f8:wlx00c0ca81fdaa:0:+sync]: record:remove ::/0 via :: dev 4 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5299] device[0x95306f8] (wlx00c0ca81fdaa): clear IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/4)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5302] device[0x95306f8] (wlx00c0ca81fdaa): clear IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/4)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5305] device[0x95306f8] (wlx00c0ca81fdaa): device not yet available for transition to DISCONNECTED
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5359] device[0x95306f8] (wlx00c0ca81fdaa): emit RECHECK_ASSUME signal
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5365] device[0x95306f8] (wlx00c0ca81fdaa): set IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/5)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5371] device[0x95306f8] (wlx00c0ca81fdaa): set IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/5)
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5372] device[0x95306f8] (wlx00c0ca81fdaa): device has no existing configuration
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5372] manager: (wlx00c0ca81fdaa): can't assume; no connection
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5385] device[0x95306f8] (wlx00c0ca81fdaa): emit RECHECK_ASSUME signal
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5386] device[0x95306f8] (wlx00c0ca81fdaa): device has no existing configuration
Apr 19 15:14:39 compy NetworkManager[678]: <debug> [1461093279.5386] manager: (wlx00c0ca81fdaa): can't assume; no connection
Apr 19 15:14:44 compy NetworkManager[678]: <debug> [1461093284.6403] manager: check_if_startup_complete returns FALSE because of wlx00c0ca81fdaa
Apr 19 15:14:44 compy NetworkManager[678]: <debug> [1461093284.6403] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (0): 'carrier wait'
Apr 19 15:14:53 compy NetworkManager[678]: <trace> [1461093293.4659] platform-linux: event-notification: NEWLINK, seq 0: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4660] platform: signal: link changed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4661] device[0x95306f8] (wlx00c0ca81fdaa): queued link change for ifindex 4
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4823] platform: signal: link removed: 4: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4828] manager: (wlx00c0ca81fdaa): removing device (allow_unmanage 1, managed 1)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4828] device[0x95306f8] (wlx00c0ca81fdaa): unmanaged: flags set to [platform-init,!sleeping,!loopback,!user-settings=0x10/0x59/unmanaged, set-unmanaged [platform-init=0x10], reason removed, transition-state)
Apr 19 15:14:53 compy NetworkManager[678]: <info>  [1461093293.4828] device (wlx00c0ca81fdaa): state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4828] device[0x95306f8] (wlx00c0ca81fdaa): deactivating device (reason 'removed') [36]
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4829] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (0): 'dhcp6' not pending (expected)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4829] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (0): 'autoconf6' not pending (expected)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4829] device[0x95306f8] (wlx00c0ca81fdaa): no MAC address change needed
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4830] device[0x95306f8] (wlx00c0ca81fdaa): clear IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/5)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4833] device[0x95306f8] (wlx00c0ca81fdaa): clear IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/5)
Apr 19 15:14:53 compy kernel: usb 5-3: ath9k_htc: USB layer deinitialized
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4920] device[0x95306f8] (wlx00c0ca81fdaa): disposing
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4921] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (0): 'dhcp6' not pending (expected)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4921] device[0x95306f8] (wlx00c0ca81fdaa): remove_pending_action (0): 'autoconf6' not pending (expected)
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.4921] device[0x95306f8] (wlx00c0ca81fdaa): will disable userland IPv6LL
Apr 19 15:14:53 compy NetworkManager[678]: <warn>  [1461093293.5131] device (wlx00c0ca81fdaa): failed to disable userspace IPv6LL address handling
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.5132] device[0x95306f8] (wlx00c0ca81fdaa): finalize(): NMDeviceEthernet
Apr 19 15:14:53 compy NetworkManager[678]: <debug> [1461093293.5134] platform-linux: UDEV event: action 'remove' subsys 'net' device 'wlx00c0ca81fdaa' (4); seqnum=1713
Apr 19 15:14:53 compy NetworkManager[678]: <info>  [1461093293.5136] devices removed (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
Apr 19 15:14:57 compy kernel: usb 5-3: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
Apr 19 15:14:57 compy kernel: usb 5-3: firmware: direct-loading firmware ath9k_htc/htc_9271-1.4.0.fw
Apr 19 15:14:57 compy kernel: usb 5-3: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
Apr 19 15:14:57 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: HTC initialized with 33 credits
Apr 19 15:14:58 compy kernel: ath9k_htc 5-3:1.0: ath9k_htc: FW Version: 1.4
Apr 19 15:14:58 compy kernel: ath9k_htc 5-3:1.0: FW RMW support: On
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.0313] platform: signal: link   added: 5: wlan0 <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy kernel: ath9k_htc 5-3:1.0 wlx00c0ca81fdaa: renamed from wlan0
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.2555] rfkill1: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/ieee80211/phy1/rfkill1) (driver ath9k_htc)
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.2643] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addrgenmode eui64 addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2644] platform: signal: link changed: 5: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.2645] device (wlan0): interface index 5 renamed iface from 'wlan0' to 'wlx00c0ca81fdaa'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2690] platform-linux: UDEV event: action 'add' subsys 'net' device 'wlx00c0ca81fdaa' (5); seqnum=1722
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.2690] platform-linux: udev-add[wlx00c0ca81fdaa,5]: device added
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2692] platform: signal: link changed: 5: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? init addrgenmode eui64 addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2692] device[0x9530a00] (wlx00c0ca81fdaa): queued link change for ifindex 5
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.2693] devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa)
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.2694] device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/net/wlx00c0ca81fdaa, iface: wlx00c0ca81fdaa): no ifupdown configuration found.
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2695] device[0x9530a00] (wlx00c0ca81fdaa): unmanaged: flags set to [!sleeping,!loopback,!platform-init,!user-settings=0x0/0x59/managed, set-managed [platform-init=0x10], reason managed, transition-state)
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.2695] device (wlx00c0ca81fdaa): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Apr 19 15:14:58 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2697] device[0x9530a00] (wlx00c0ca81fdaa): will enable userland IPv6LL
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.2698] platform-linux: event-notification: NEWLINK, seq 29: 5: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2698] platform: signal: link changed: 5: wlx00c0ca81fdaa <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2699] device[0x9530a00] (wlx00c0ca81fdaa): queued link change for ifindex 5
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2700] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '1' (current value is '0')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2700] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2701] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_defrtr' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2701] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_pinfo' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2702] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_rtr_pref' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2702] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2702] device[0x9530a00] (wlx00c0ca81fdaa): bringing up device
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.2702] platform: link: setting up 'wlx00c0ca81fdaa' (5)
Apr 19 15:14:58 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4416] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up,running> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4417] platform: signal: link changed: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up,running> mtu 1500 arp 1 wifi? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4418] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4419] platform: signal: link changed: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4419] platform-linux: event-notification: NEWLINK, seq 31: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4420] device[0x9530a00] (wlx00c0ca81fdaa): preparing device
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4420] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (0): 'dhcp6' not pending (expected)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4421] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (0): 'autoconf6' not pending (expected)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4421] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4422] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4422] device[0x9530a00] (wlx00c0ca81fdaa): no MAC address change needed
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4424] default-route: entry[0/dev:0x9530a00:wlx00c0ca81fdaa:0:+sync]: record:add    0.0.0.0/0 via 0.0.0.0 dev 5 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4424] default-route: entry[0/dev:0x9530a00:wlx00c0ca81fdaa:0:+sync]: record:add    ::/0 via :: dev 5 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4425] default-route: entry[0/dev:0x9530a00:wlx00c0ca81fdaa:0:+sync]: record:remove 0.0.0.0/0 via 0.0.0.0 dev 5 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4425] default-route: entry[0/dev:0x9530a00:wlx00c0ca81fdaa:0:+sync]: record:remove ::/0 via :: dev 5 metric 4294967295 mss 0 src unknown (4294967295)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4425] device[0x9530a00] (wlx00c0ca81fdaa): clear IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/6)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4431] device[0x9530a00] (wlx00c0ca81fdaa): clear IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/6)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4439] supplicant: (wlx00c0ca81fdaa): creating new supplicant interface
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4440] sup-iface[0x9565290,wlx00c0ca81fdaa]: adding interface to supplicant
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4441] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (1): 'waiting for supplicant'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4442] device[0x9530a00] (wlx00c0ca81fdaa): device not yet available for transition to DISCONNECTED
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4446] platform-linux: UDEV event: action 'move' subsys 'net' device 'wlx00c0ca81fdaa' (5); seqnum=1731
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4446] platform-linux: udev-add[wlx00c0ca81fdaa,5]: device added
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4448] platform: signal: link changed: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4479] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4855] sup-iface[0x9565290,wlx00c0ca81fdaa]: interface added to supplicant
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.4875] sup-iface[0x9565290,wlx00c0ca81fdaa]: supports 4 scan SSIDs
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4885] sup-iface[0x9565290,wlx00c0ca81fdaa]: supplicant supports network credentials requests
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.4889] device (wlx00c0ca81fdaa): supplicant interface state: starting -> ready
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4890] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (0): 'waiting for supplicant'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4891] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (1): 'queued state change to disconnected'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4891] device[0x9530a00] (wlx00c0ca81fdaa): queued state change to disconnected due to supplicant-available (id 191)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4891] device[0x9530a00] (wlx00c0ca81fdaa): is available, will transition to disconnected
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4891] device[0x9530a00] (wlx00c0ca81fdaa): running queued state change to disconnected (id 191)
Apr 19 15:14:58 compy NetworkManager[678]: <info>  [1461093298.4892] device (wlx00c0ca81fdaa): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4892] device[0x9530a00] (wlx00c0ca81fdaa): will enable userland IPv6LL
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4895] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy kernel: IPv6: ADDRCONF(NETDEV_UP): wlx00c0ca81fdaa: link is not ready
Apr 19 15:14:58 compy NetworkManager[678]: <trace> [1461093298.4895] platform-linux: event-notification: NEWLINK, seq 33: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4897] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '1' (current value is '0')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4897] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/disable_ipv6' to '0' (current value is '1')
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4898] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_defrtr' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4898] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_pinfo' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4899] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/accept_ra_rtr_pref' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4900] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/wlx00c0ca81fdaa/use_tempaddr' to '0' (current value is identical)
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4909] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (2): 'scan'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4909] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (3): 'autoactivate'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4910] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (2): 'queued state change to disconnected'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4912] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (1): 'scan'
Apr 19 15:14:58 compy NetworkManager[678]: <debug> [1461093298.4917] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (0): 'autoactivate'
Apr 19 15:14:59 compy NetworkManager[678]: <trace> [1461093299.6603] platform-linux: event-notification: NEWLINK, seq 0: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 0 arp 1 wifi? not-init
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6604] platform: signal: link changed: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 0 arp 1 wifi? init driver ath9k_htc
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6605] device[0x9530a00] (wlx00c0ca81fdaa): queued link change for ifindex 5
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6637] device (wlx00c0ca81fdaa): supplicant interface state: ready -> inactive
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6682] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (1): 'autoactivate'
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6689] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (0): 'autoactivate'
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6721] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (1): 'autoactivate'
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6778] active-connection[0x9557940]: set device "wlx00c0ca81fdaa" [0x9530a00]
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6778] device[0x9530a00] (wlx00c0ca81fdaa): add_pending_action (2): 'activation::0x9557940'
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6778] device[0x9530a00] (wlx00c0ca81fdaa): remove_pending_action (1): 'autoactivate'
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6779] device[0x9530a00] (wlx00c0ca81fdaa): unmanaged: flags set to [!sleeping,!loopback,!platform-init,!user-explicit,!user-settings=0x0/0x79/managed, set-managed [user-explicit=0x20], reason user-requested)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6783] device (wlx00c0ca81fdaa): Activation: starting connection 'MY_SSID' (7fd5e7fd-f61e-4428-bf70-121047bb6e60)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6784] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: schedule activate_stage1_device_prepare,2 (id 289)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6785] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: invoke activate_stage1_device_prepare,2 (id 289)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6785] device (wlx00c0ca81fdaa): state change: disconnected -> prepare (reason 'none') [30 40 0]
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6789] device[0x9530a00] (wlx00c0ca81fdaa): no MAC address change needed
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6789] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: schedule activate_stage2_device_config,2 (id 297)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6790] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: complete activate_stage1_device_prepare,2 (id 289)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6793] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: invoke activate_stage2_device_config,2 (id 297)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6793] device (wlx00c0ca81fdaa): state change: prepare -> config (reason 'none') [40 50 0]
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6794] device[0x9530a00] (wlx00c0ca81fdaa): bringing up device
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6795] platform: link: setting up 'wlx00c0ca81fdaa' (5)
Apr 19 15:14:59 compy NetworkManager[678]: <trace> [1461093299.6796] platform-linux: event-notification: NEWLINK, seq 35: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6796] platform: signal: link changed: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? init addrgenmode none addr 00:C0:CA:81:FD:AA driver ath9k_htc
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6796] device[0x9530a00] (wlx00c0ca81fdaa): queued link change for ifindex 5
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6797] device (wlx00c0ca81fdaa): Activation: (wifi) access point 'MY_SSID' has security, but secrets are required.
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6797] device (wlx00c0ca81fdaa): state change: config -> need-auth (reason 'none') [50 60 0]
Apr 19 15:14:59 compy wpa_supplicant[3575]: wlx00c0ca81fdaa: SME: Trying to authenticate with MY_BSSID (SSID='MY_SSID' freq=2412 MHz)
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: authenticate with MY_BSSID
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6813] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: complete activate_stage2_device_config,2 (id 297)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6843] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: schedule activate_stage1_device_prepare,2 (id 308)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6848] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: invoke activate_stage1_device_prepare,2 (id 308)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6848] device (wlx00c0ca81fdaa): state change: need-auth -> prepare (reason 'none') [60 40 0]
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6850] device[0x9530a00] (wlx00c0ca81fdaa): no MAC address change needed
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6851] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: schedule activate_stage2_device_config,2 (id 312)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6851] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: complete activate_stage1_device_prepare,2 (id 308)
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6853] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: invoke activate_stage2_device_config,2 (id 312)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6853] device (wlx00c0ca81fdaa): state change: prepare -> config (reason 'none') [40 50 0]
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6854] device[0x9530a00] (wlx00c0ca81fdaa): bringing up device
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6854] platform: link: setting up 'wlx00c0ca81fdaa' (5)
Apr 19 15:14:59 compy NetworkManager[678]: <trace> [1461093299.6857] platform-linux: event-notification: NEWLINK, seq 37: 5: wlx00c0ca81fdaa <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addrgenmode none addr 00:C0:CA:81:FD:AA
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6857] device (wlx00c0ca81fdaa): Activation: (wifi) connection 'MY_SSID' has security, and secrets exist.  No new secrets needed.
Apr 19 15:14:59 compy NetworkManager[678]: <trace> [1461093299.6857] device[0x9530a00] (wlx00c0ca81fdaa): powersave is set to 1
Apr 19 15:14:59 compy NetworkManager[678]: <debug> [1461093299.6860] device[0x9530a00] (wlx00c0ca81fdaa): activation-stage: complete activate_stage2_device_config,2 (id 312)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.6864] sup-iface[0x9565290,wlx00c0ca81fdaa]: config: set interface ap_scan to 1
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.9012] device (wlx00c0ca81fdaa): supplicant interface state: inactive -> authenticating
Apr 19 15:14:59 compy wpa_supplicant[3575]: wlx00c0ca81fdaa: Trying to associate with MY_BSSID (SSID='MY_SSID' freq=2412 MHz)
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: send auth to MY_BSSID (try 1/3)
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: authenticated
Apr 19 15:14:59 compy kernel: ath9k_htc 5-3:1.0 wlx00c0ca81fdaa: disabling HT/VHT due to WEP/TKIP use
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: associate with MY_BSSID (try 1/3)
Apr 19 15:14:59 compy NetworkManager[678]: <info>  [1461093299.9081] device (wlx00c0ca81fdaa): supplicant interface state: authenticating -> associating
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: RX AssocResp from MY_BSSID (capab=0x411 status=0 aid=3)
Apr 19 15:14:59 compy wpa_supplicant[3575]: wlx00c0ca81fdaa: Associated with MY_BSSID
Apr 19 15:14:59 compy kernel: wlx00c0ca81fdaa: associated
Apr 19 15:14:59 compy kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlx00c0ca81fdaa: link becomes ready
[...]
Comment 5 Jason Woofenden 2016-04-20 21:58:59 UTC 
@dan here's the output of those commands:

cat /sys/class/net/<interface name>/uevent

	DEVTYPE=wlan
	INTERFACE=wlx00c0ca81fdaa
	IFINDEX=4

ls -alp /sys/class/net/<interface name>/phy80211

	lrwxrwxrwx 1 root root 0 Apr 20 17:54 /sys/class/net/wlx00c0ca81fdaa//phy80211 -> ../../ieee80211/phy0

This is shortly after booting, when it did not connect automatically.

After unplugging the wifi device and plugging it back in, the output appeared the same, except IFINDEX changed to 5.
Comment 6 Beniamino Galvani 2016-04-21 11:42:56 UTC 
*** Bug 765123 has been marked as a duplicate of this bug. ***
Comment 7 Beniamino Galvani 2016-04-21 11:46:20 UTC 
Created attachment 326481 [details] [review]
[PATCH] platform: add logs to debug link type matching

Is there any chance you (or anybody else) can rebuild the NM package
with the attached patch and post trace logs? I've tried with some wifi
cards with different chipsets but I'm not able to reproduce the
problem.
Comment 8 Thomas Haller 2016-04-21 13:27:15 UTC 
Created attachment 326489 [details] [review]
[v2 for master] 0001-platform-add-logs-to-debug-link-type-matching.patch

(In reply to Beniamino Galvani from comment #7)
> Created attachment 326481 [details] [review] [review]
> [PATCH] platform: add logs to debug link type matching
> 
> Is there any chance you (or anybody else) can rebuild the NM package
> with the attached patch and post trace logs? I've tried with some wifi
> cards with different chipsets but I'm not able to reproduce the
> problem.

Ups, I just merged something to master so that the patch no longer applies there.

If you happen to compile master, please use this patch instead. Or whatever applies... Sorry for the inconvenience.
Comment 9 Tatsuyuki Ishi 2016-04-23 23:20:10 UTC 
Confirmed on:
ThinkPad X1 Yoga
Wireless Card: 04:00.0 Network controller: Intel Corporation Wireless 8260 (rev 3a)

I will take some logs when I'm free.

Additional Notes:
This occurs on boot but will be fixed if I restart NM by systemctl after login to desktop environment.
Comment 10 Tatsuyuki Ishi 2016-04-24 00:24:54 UTC 
Created attachment 326613 [details]
NM trace log including working after restart

I took a fresh log.
I accidentally restarted the service before taking the log, so this contains the broken one first and then the working one.
Comment 11 Beniamino Galvani 2016-04-24 19:24:28 UTC 
Created attachment 326642 [details] [review]
[PATCH] platform: reuse cached type only for udev-initialized links

> link-type: get type for "wlan0" ifindex 2 arptype 1, kind (null)
> link-type: trying ethtool
> link-type: trying sysfs
> link-type: devtype (null)
> link-type: 'wlan0' phy80211 -1, mode 0
> link-type: ethernet (no kind or devtype)

It seems we are trying to access sysfs after the device has been renamed by udev; the wrong link type is then cached and never refreshed.

A solution would be to ignore links from the cache until they are announced by udev as the type determined before the announcement is unreliable due to race conditions with the rename.

Thomas, what do you think of the attached patch?
Comment 12 Tatsuyuki Ishi 2016-04-29 08:23:03 UTC 
The attached patch works properly. I have to hand-apply it though because it's out-of-sync.

Tested-by: Tatsuyuki Ishi <ishitatsuyuki@gmail.com>
Comment 14 Thomas Haller 2016-04-30 14:40:41 UTC 
*** Bug 765839 has been marked as a duplicate of this bug. ***
Comment 15 Thomas Haller 2016-05-09 19:49:46 UTC 
*** Bug 766192 has been marked as a duplicate of this bug. ***
Comment 16 Beniamino Galvani 2016-05-24 21:43:30 UTC 
*** Bug 766786 has been marked as a duplicate of this bug. ***
Comment 17 Beniamino Galvani 2016-06-07 16:36:35 UTC 
*** Bug 767243 has been marked as a duplicate of this bug. ***
Comment 18 slesru 2016-07-03 10:07:32 UTC 
I run ubuntu 16.04, which includes commit from above, but I still have problem that sometimes trendnet wifi is recognized as wired link.
So, bug is not fixed by this commit.
Thank you!
Comment 19 Tatsuyuki Ishi 2016-07-03 10:11:19 UTC 
No, it works. You should check again if you have the up-to-date version, and attach a debug log if you think it's still wrong.
Comment 20 Tatsuyuki Ishi 2016-07-03 10:11:44 UTC 
No, it works. You should check again if you have the up-to-date version, and attach a debug log if you think it's still wrong.
Comment 21 Tatsuyuki Ishi 2016-07-03 10:12:16 UTC 
Oh, sorry for my duplicate comment.
Comment 22 slesru 2016-07-04 05:59:13 UTC 
No, it doesn't.
Yes, I have up to date version- I downloaded package sources and "fix" is there.
Once I'll have this problem again I'll upload log...
Comment 23 slesru 2016-07-08 06:13:37 UTC 
What is interesting I can't reproduce bug with TRACE loglevel.
This means network manager slows down enough to avoid race codition in this case.
Not a problem, and even useful, but logs wore out my ssd :-(
Hope it will be reproduced somewhen, though...
Comment 24 slesru 2016-07-24 03:50:45 UTC 
Created attachment 332031 [details]
log with NM thinks wifi is wired usb

Finally, I got this reproduced.
NM think atheros wifi is wired usb...
Comment 25 Eugene Kanter 2017-05-23 16:20:48 UTC 
Strange, but a year later I still see similar problem:
# NetworkManager --version
1.4.0-19.el7_3

# lshw
...
*-usb
  description: Wireless interface
  product: Edimax AC600 USB
  vendor: Realtek
  physical id: 8
  bus info: usb@2:1.8
  logical name: enp0s29u1u8
  version: 2.00
  serial: 
  capabilities: usb-2.10 ethernet physical wireless
  configuration: broadcast=yes driver=rtl8821au maxpower=500mA multicast=yes speed=480Mbit/s wireless=unassociated

# nmcli device show enp0s29u1u8
GENERAL.DEVICE:                         enp0s29u1u8
GENERAL.TYPE:                           ethernet
GENERAL.HWADDR:                         xx:xx:xx:xx:xx:xx
GENERAL.MTU:                            0
GENERAL.STATE:                          30 (disconnected)
GENERAL.CONNECTION:                     --
GENERAL.CON-PATH:                       --
WIRED-PROPERTIES.CARRIER:               on
Comment 26 slesru 2017-05-30 17:22:34 UTC 
Still have this problem , just wrote script which reloads ath module and click it :-D