Bug#947283: network-manager: fails to connect via Wi-Fi with "selecting lease failed"

Mon, 23 Dec 2019 14:30:47 -0800 

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

When connecting to a Starbucks Wi-Fi network (open Wi-Fi network with
captive portal), Network Manager refuses to get an IPv4 address over
DHCP with a message in the logs that says "selecting lease failed: 12".
This machine has not previously been connected to this network.
Downgrading to 1.20.8-1 causes things to work again, but 1.22.0-1 does
not work even if I reboot and delete all the saved leases from
/var/lib/NetworkManager.

I don't see the problem on my home network, with uses WPA2-EAP with
EAP-TTLS and PAP.  However, I had connected to that network before
installing 1.22.0, so it's possible that the issue is with new networks.

Relevant portions of the logs from 1.22.0-1 and 1.20.8-1 are attached.

-- System Information:
Debian Release: bullseye/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable'), (1, 
'experimental')
Architecture: amd64 (x86_64)

Kernel: Linux 5.3.0-3-amd64 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), 
LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages network-manager depends on:
ii  adduser                3.118
ii  dbus                   1.12.16-2
ii  init-system-helpers    1.57
ii  libaudit1              1:2.8.5-2+b1
ii  libbluetooth3          5.50-1+b1
ii  libc6                  2.29-6
ii  libcurl3-gnutls        7.67.0-2
ii  libglib2.0-0           2.62.3-2
ii  libgnutls30            3.6.11.1-2
ii  libjansson4            2.12-1
ii  libmm-glib0            1.10.4-0.1
ii  libndp0                1.6-1+b1
ii  libnewt0.52            0.52.21-4
ii  libnm0                 1.22.0-1
ii  libpam-systemd         244-3
ii  libpolkit-agent-1-0    0.105-26
ii  libpolkit-gobject-1-0  0.105-26
ii  libpsl5                0.20.2-2
ii  libreadline8           8.0-3
ii  libselinux1            3.0-1
ii  libsystemd0            244-3
ii  libteamdctl0           1.29-1
ii  libudev1               244-3
ii  libuuid1               2.34-0.1
ii  policykit-1            0.105-26
ii  udev                   244-3
ii  wpasupplicant          2:2.9-3+b1

Versions of packages network-manager recommends:
ii  crda                         3.18-1
ii  dnsmasq-base [dnsmasq-base]  2.80-1.1
ii  iptables                     1.8.4-1
ii  modemmanager                 1.10.4-0.1
ii  ppp                          2.4.7-2+4.1+b1

Versions of packages network-manager suggests:
ii  isc-dhcp-client  4.4.1-2
pn  libteam-utils    <none>

-- no debconf information

-- 
brian m. carlson: Houston, Texas, US
OpenPGP: https://keybase.io/bk2204

Dec 23 18:19:35 camp NetworkManager[219829]: <info>  [1577125175.9758] dhcp4 
(wlp0s20f3): state changed bound -> expire
Dec 23 18:19:35 camp NetworkManager[219829]: <info>  [1577125175.9759] device 
(wlp0s20f3): DHCPv4: 480 seconds grace period started
Dec 23 18:19:35 camp NetworkManager[219829]: <warn>  [1577125175.9774] 
sup-iface[0x556830be74c0,wlp0s20f3]: connection disconnected (reason -3)
Dec 23 18:19:35 camp NetworkManager[219829]: <info>  [1577125175.9798] device 
(wlp0s20f3): supplicant interface state: completed -> disconnected
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.5802] manager: 
sleep: wake requested (sleeping: yes  enabled: yes)
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.5803] device 
(enp0s31f6): state change: unavailable -> unmanaged (reason 'sleeping', 
sys-iface-state: 'managed')
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6639] device 
(wlp0s20f3): state change: activated -> unmanaged (reason 'sleeping', 
sys-iface-state: 'managed')
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6640] dhcp4 
(wlp0s20f3): canceled DHCP transaction
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6640] dhcp4 
(wlp0s20f3): state changed expire -> done
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6713] manager: 
NetworkManager state is now CONNECTED_GLOBAL
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6916] manager: 
NetworkManager state is now CONNECTED_LOCAL
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.6923] device 
(enp0s31f6): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'managed')
Dec 23 18:19:36 camp NetworkManager[219829]: <info>  [1577125176.8839] device 
(wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'managed')
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.1050] device 
(wlp0s20f3): set-hw-addr: set MAC address to DA:6B:EA:90:07:84 (scanning)
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3101] device 
(F0:5C:77:DA:5B:F8): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'managed')
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3125] device 
(p2p-dev-wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'managed')
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3167] device 
(F0:5C:77:DA:5B:F8): state change: unavailable -> disconnected (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3915] 
sup-iface[0x556830be74c0,wlp0s20f3]: supports 5 scan SSIDs
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3931] device 
(wlp0s20f3): supplicant interface state: starting -> ready
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3933] device 
(p2p-dev-wlp0s20f3): state change: unavailable -> disconnected (reason 
'supplicant-available', sys-iface-state: 'managed')
Dec 23 18:19:37 camp NetworkManager[219829]: <info>  [1577125177.3943] device 
(wlp0s20f3): state change: unavailable -> disconnected (reason 
'supplicant-available', sys-iface-state: 'managed')
Dec 23 18:20:01 camp NetworkManager[219829]: <info>  [1577125201.9467] device 
(wlp0s20f3): Activation: starting connection 'Starbucks WiFi' 
(0ac9ba60-93d3-4e5e-9d37-070e258b56e6)
Dec 23 18:20:01 camp NetworkManager[219829]: <info>  [1577125201.9469] audit: 
op="connection-add-activate" uuid="0ac9ba60-93d3-4e5e-9d37-070e258b56e6" 
name="Starbucks WiFi" pid=1719 uid=1000 result="success"
Dec 23 18:20:01 camp NetworkManager[219829]: <info>  [1577125201.9472] device 
(wlp0s20f3): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:20:01 camp NetworkManager[219829]: <info>  [1577125201.9477] manager: 
NetworkManager state is now CONNECTING
Dec 23 18:20:01 camp NetworkManager[219829]: <info>  [1577125201.9695] device 
(wlp0s20f3): set-hw-addr: reset MAC address to 04:ED:33:EF:98:27 (preserve)
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1791] device 
(wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1799] device 
(wlp0s20f3): Activation: (wifi) connection 'Starbucks WiFi' requires no 
security.  No secrets needed.
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1800] Config: 
added 'ssid' value 'Starbucks WiFi'
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1800] Config: 
added 'scan_ssid' value '1'
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1801] Config: 
added 'bgscan' value 'simple:30:-70:86400'
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.1801] Config: 
added 'key_mgmt' value 'NONE'
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2094] device 
(wlp0s20f3): supplicant interface state: ready -> disabled
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2095] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: ready -> disabled
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2305] device 
(wlp0s20f3): supplicant interface state: disabled -> inactive
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2306] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: disabled -> inactive
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2372] device 
(wlp0s20f3): supplicant interface state: inactive -> scanning
Dec 23 18:20:02 camp NetworkManager[219829]: <info>  [1577125202.2372] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: inactive -> scanning
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.1755] device 
(wlp0s20f3): supplicant interface state: scanning -> authenticating
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.1755] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: scanning -> 
authenticating
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2158] device 
(wlp0s20f3): supplicant interface state: authenticating -> associating
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2159] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: authenticating -> 
associating
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2315] device 
(wlp0s20f3): supplicant interface state: associating -> completed
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2316] device 
(wlp0s20f3): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. 
Connected to wireless network "Starbucks WiFi"
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2316] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: associating -> 
completed
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2330] device 
(wlp0s20f3): state change: config -> ip-config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:20:05 camp NetworkManager[219829]: <info>  [1577125205.2341] dhcp4 
(wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Dec 23 18:20:08 camp NetworkManager[219829]: <warn>  [1577125208.1178] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:20:12 camp NetworkManager[219829]: <warn>  [1577125212.9334] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:20:21 camp NetworkManager[219829]: <warn>  [1577125221.0580] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:20:41 camp NetworkManager[219829]: <warn>  [1577125241.1040] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:20:50 camp NetworkManager[219829]: <warn>  [1577125250.5553] dhcp4 
(wlp0s20f3): request timed out
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5554] dhcp4 
(wlp0s20f3): state changed unknown -> timeout
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5555] device 
(wlp0s20f3): state change: ip-config -> failed (reason 'ip-config-unavailable', 
sys-iface-state: 'managed')
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5571] manager: 
NetworkManager state is now CONNECTED_LOCAL
Dec 23 18:20:50 camp NetworkManager[219829]: <warn>  [1577125250.5602] device 
(wlp0s20f3): Activation: failed for connection 'Starbucks WiFi'
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5606] device 
(wlp0s20f3): state change: failed -> disconnected (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5938] dhcp4 
(wlp0s20f3): canceled DHCP transaction
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.5939] dhcp4 
(wlp0s20f3): state changed timeout -> done
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.6279] device 
(wlp0s20f3): set-hw-addr: set MAC address to 1E:8F:4D:8B:EF:96 (scanning)
Dec 23 18:20:50 camp NetworkManager[219829]: <warn>  [1577125250.8419] 
sup-iface[0x556830be74c0,wlp0s20f3]: connection disconnected (reason -3)
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.8419] device 
(wlp0s20f3): supplicant interface state: completed -> disconnected
Dec 23 18:20:50 camp NetworkManager[219829]: <info>  [1577125250.8419] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: completed -> 
disconnected
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.6220] device 
(wlp0s20f3): Activation: starting connection 'Starbucks WiFi' 
(0ac9ba60-93d3-4e5e-9d37-070e258b56e6)
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.6221] audit: 
op="connection-activate" uuid="0ac9ba60-93d3-4e5e-9d37-070e258b56e6" 
name="Starbucks WiFi" pid=1719 uid=1000 result="success"
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.6222] device 
(wlp0s20f3): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.6225] manager: 
NetworkManager state is now CONNECTING
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.6390] device 
(wlp0s20f3): set-hw-addr: reset MAC address to 04:ED:33:EF:98:27 (preserve)
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8450] device 
(wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8458] device 
(wlp0s20f3): Activation: (wifi) connection 'Starbucks WiFi' requires no 
security.  No secrets needed.
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8459] Config: 
added 'ssid' value 'Starbucks WiFi'
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8459] Config: 
added 'scan_ssid' value '1'
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8460] Config: 
added 'bgscan' value 'simple:30:-70:86400'
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8460] Config: 
added 'key_mgmt' value 'NONE'
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8664] device 
(wlp0s20f3): supplicant interface state: disconnected -> disabled
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8664] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: disconnected -> 
disabled
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8910] device 
(wlp0s20f3): supplicant interface state: disabled -> disconnected
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8911] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: disabled -> 
disconnected
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8999] device 
(wlp0s20f3): supplicant interface state: disconnected -> scanning
Dec 23 18:20:58 camp NetworkManager[219829]: <info>  [1577125258.8999] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: disconnected -> 
scanning
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.8739] device 
(wlp0s20f3): supplicant interface state: scanning -> authenticating
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.8749] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: scanning -> 
authenticating
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.8993] device 
(wlp0s20f3): supplicant interface state: authenticating -> associating
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.8993] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: authenticating -> 
associating
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.9185] device 
(wlp0s20f3): supplicant interface state: associating -> completed
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.9185] device 
(wlp0s20f3): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. 
Connected to wireless network "Starbucks WiFi"
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.9185] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: associating -> 
completed
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.9195] device 
(wlp0s20f3): state change: config -> ip-config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:21:01 camp NetworkManager[219829]: <info>  [1577125261.9202] dhcp4 
(wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Dec 23 18:21:01 camp NetworkManager[219829]: <warn>  [1577125261.9264] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:21:04 camp NetworkManager[219829]: <warn>  [1577125264.1479] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:21:08 camp NetworkManager[219829]: <warn>  [1577125268.6799] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:21:19 camp NetworkManager[219829]: <warn>  [1577125279.0950] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:21:33 camp NetworkManager[219829]: <warn>  [1577125293.0289] dhcp4 
(wlp0s20f3): selecting lease failed: 12
Dec 23 18:21:47 camp NetworkManager[219829]: <warn>  [1577125307.5579] dhcp4 
(wlp0s20f3): request timed out
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5580] dhcp4 
(wlp0s20f3): state changed unknown -> timeout
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5581] device 
(wlp0s20f3): state change: ip-config -> failed (reason 'ip-config-unavailable', 
sys-iface-state: 'managed')
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5591] manager: 
NetworkManager state is now CONNECTED_LOCAL
Dec 23 18:21:47 camp NetworkManager[219829]: <warn>  [1577125307.5619] device 
(wlp0s20f3): Activation: failed for connection 'Starbucks WiFi'
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5628] device 
(wlp0s20f3): state change: failed -> disconnected (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5899] dhcp4 
(wlp0s20f3): canceled DHCP transaction
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.5899] dhcp4 
(wlp0s20f3): state changed timeout -> done
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.6253] device 
(wlp0s20f3): set-hw-addr: set MAC address to 76:FE:7C:32:48:60 (scanning)
Dec 23 18:21:47 camp NetworkManager[219829]: <warn>  [1577125307.8399] 
sup-iface[0x556830be74c0,wlp0s20f3]: connection disconnected (reason -3)
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.8400] device 
(wlp0s20f3): supplicant interface state: completed -> disconnected
Dec 23 18:21:47 camp NetworkManager[219829]: <info>  [1577125307.8400] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: completed -> 
disconnected
Dec 23 18:22:22 camp NetworkManager[219829]: <info>  [1577125342.8178] caught 
SIGTERM, shutting down normally.
Dec 23 18:22:22 camp NetworkManager[219829]: <info>  [1577125342.8216] device 
(p2p-dev-wlp0s20f3): state change: disconnected -> unmanaged (reason 'removed', 
sys-iface-state: 'removed')
Dec 23 18:22:22 camp NetworkManager[219829]: <info>  [1577125342.8220] device 
(F0:5C:77:DA:5B:F8): state change: disconnected -> unmanaged (reason 
'unmanaged', sys-iface-state: 'managed')
Dec 23 18:22:22 camp NetworkManager[219829]: <info>  [1577125342.8346] exiting 
(success)

Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.3946] 
NetworkManager (version 1.20.8) is starting... (after a restart)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.3946] Read 
config: /etc/NetworkManager/NetworkManager.conf (lib: no-mac-addr-change.conf)
Dec 23 18:38:32 camp NetworkManager[7818]: <warn>  [1577126312.3947] config: 
unknown key 'wifi.cloned-mac-address' in section [device-mac-addr-change-wifi] 
of file '/usr/lib/NetworkManager/conf.d/no-mac-addr-change.conf'
Dec 23 18:38:32 camp NetworkManager[7818]: <warn>  [1577126312.3947] config: 
unknown key 'ethernet.cloned-mac-address' in section 
[device-mac-addr-change-wifi] of file 
'/usr/lib/NetworkManager/conf.d/no-mac-addr-change.conf'
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.3958] 
bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.3973] 
manager[0x5613abce80c0]: monitoring kernel firmware directory '/lib/firmware'.
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.3973] monitoring 
ifupdown state file '/run/network/ifstate'.
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6522] hostname: 
hostname: using hostnamed
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6523] hostname: 
hostname changed from (none) to "camp"
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6525] 
dns-mgr[0x5613abccb240]: init: dns=default,systemd-resolved rc-manager=immutable
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6530] rfkill1: 
found Wi-Fi radio killswitch (at 
/sys/devices/pci0000:00/0000:00:14.3/ieee80211/phy0/rfkill1) (driver iwlwifi)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6532] 
manager[0x5613abce80c0]: rfkill: Wi-Fi hardware radio set enabled
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6532] 
manager[0x5613abce80c0]: rfkill: WWAN hardware radio set enabled
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6541] Loaded 
device plugin: NMWifiFactory 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-device-plugin-wifi.so)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6549] Loaded 
device plugin: NMWwanFactory 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-device-plugin-wwan.so)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6551] Loaded 
device plugin: NMAtmManager 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-device-plugin-adsl.so)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6557] Loaded 
device plugin: NMTeamFactory 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-device-plugin-team.so)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6560] Loaded 
device plugin: NMBluezManager 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-device-plugin-bluetooth.so)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6562] manager: 
rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6563] manager: 
rfkill: WWAN enabled by radio killswitch; enabled by state file
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6564] manager: 
Networking is enabled by state file
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6565] dhcp-init: 
Using DHCP client 'internal'
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6567] settings: 
Loaded settings plugin: ifupdown 
("/usr/lib/x86_64-linux-gnu/NetworkManager/1.20.8/libnm-settings-plugin-ifupdown.so")
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6567] settings: 
Loaded settings plugin: keyfile (internal)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6567] ifupdown: 
management mode: unmanaged
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6567] ifupdown:  
     interface-parser: parsing file /etc/network/interfaces
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6567] ifupdown:  
     interface-parser: source line includes interfaces file(s) 
/etc/network/interfaces.d/*
Dec 23 18:38:32 camp NetworkManager[7818]: <warn>  [1577126312.6568] ifupdown: 
interfaces file /etc/network/interfaces.d/* doesn't exist
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6568] ifupdown:  
     interface-parser: finished parsing file /etc/network/interfaces
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6636] device 
(lo): carrier: link connected
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6637] manager: 
(lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6645] manager: 
(docker0): new Bridge device (/org/freedesktop/NetworkManager/Devices/2)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6657] manager: 
(docker0): assume: will attempt to assume matching connection 'docker0' 
(cfd303ee-a10a-456b-bc7e-eedc40512a67) (indicated)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6657] device 
(docker0): state change: unmanaged -> unavailable (reason 'connection-assumed', 
sys-iface-state: 'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6672] device 
(docker0): state change: unavailable -> disconnected (reason 
'connection-assumed', sys-iface-state: 'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6681] device 
(docker0): Activation: starting connection 'docker0' 
(cfd303ee-a10a-456b-bc7e-eedc40512a67)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6685] manager: 
(enp0s31f6): new Ethernet device (/org/freedesktop/NetworkManager/Devices/3)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6692] device 
(enp0s31f6): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'external')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6708] device 
(wlp0s20f3): driver supports Access Point (AP) mode
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6712] manager: 
(wlp0s20f3): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/4)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6720] device 
(wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'external')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.6870] device 
(wlp0s20f3): set-hw-addr: set MAC address to 42:0E:B9:97:C5:43 (scanning)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8869] device 
(docker0): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8872] device 
(docker0): state change: prepare -> config (reason 'none', sys-iface-state: 
'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8981] bluez: use 
BlueZ version 5
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8983] 
supplicant: wpa_supplicant running
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8983] device 
(wlp0s20f3): supplicant interface state: init -> starting
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8983] 
modem-manager: ModemManager available
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8989] 
agent-manager: req[0x5613abd6cb60, :1.80/org.freedesktop.nm-applet/1000]: agent 
registered
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.8993] device 
(docker0): state change: config -> ip-config (reason 'none', sys-iface-state: 
'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9003] device 
(docker0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 
'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9029] device 
(docker0): state change: ip-check -> secondaries (reason 'none', 
sys-iface-state: 'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9043] bluez5: 
NAP: added interface 04:ED:33:EF:98:2B
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9048] device 
(docker0): state change: secondaries -> activated (reason 'none', 
sys-iface-state: 'assume')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9053] manager: 
NetworkManager state is now CONNECTED_LOCAL
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9058] device 
(docker0): Activation: successful, device activated.
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9146] bluez: BT 
device ska (F0:5C:77:DA:5B:F8) added (NAP)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9150] manager: 
(F0:5C:77:DA:5B:F8): new Bluetooth device 
(/org/freedesktop/NetworkManager/Devices/5)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9155] device 
(F0:5C:77:DA:5B:F8): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'external')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9234] device 
(F0:5C:77:DA:5B:F8): state change: unavailable -> disconnected (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9754] 
sup-iface[0x5613abcfb910,wlp0s20f3]: supports 5 scan SSIDs
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9763] device 
(wlp0s20f3): supplicant interface state: starting -> ready
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9765] Wi-Fi P2P 
device controlled by interface wlp0s20f3 created
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9772] manager: 
(p2p-dev-wlp0s20f3): new 802.11 Wi-Fi P2P device 
(/org/freedesktop/NetworkManager/Devices/6)
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9779] device 
(p2p-dev-wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', 
sys-iface-state: 'external')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9794] device 
(p2p-dev-wlp0s20f3): state change: unavailable -> disconnected (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:32 camp NetworkManager[7818]: <info>  [1577126312.9801] device 
(wlp0s20f3): state change: unavailable -> disconnected (reason 
'supplicant-available', sys-iface-state: 'managed')
Dec 23 18:38:32 camp NetworkManager[7818]: <warn>  [1577126312.9830] sup-iface: 
failed to cancel p2p connect: P2P cancel failed
Dec 23 18:38:38 camp NetworkManager[7818]: <info>  [1577126318.6721] manager: 
startup complete
Dec 23 18:38:40 camp NetworkManager[7818]: <info>  [1577126320.8538] device 
(wlp0s20f3): Activation: starting connection 'Starbucks WiFi' 
(0ac9ba60-93d3-4e5e-9d37-070e258b56e6)
Dec 23 18:38:40 camp NetworkManager[7818]: <info>  [1577126320.8542] audit: 
op="connection-activate" uuid="0ac9ba60-93d3-4e5e-9d37-070e258b56e6" 
name="Starbucks WiFi" pid=1907 uid=1000 result="success"
Dec 23 18:38:40 camp NetworkManager[7818]: <info>  [1577126320.8546] device 
(wlp0s20f3): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:40 camp NetworkManager[7818]: <info>  [1577126320.8560] manager: 
NetworkManager state is now CONNECTING
Dec 23 18:38:40 camp NetworkManager[7818]: <info>  [1577126320.8724] device 
(wlp0s20f3): set-hw-addr: reset MAC address to B2:7F:4D:46:A0:07 (preserve)
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1040] device 
(wlp0s20f3): supplicant interface state: ready -> disabled
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1040] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: ready -> disabled
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1044] device 
(wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1049] device 
(wlp0s20f3): Activation: (wifi) connection 'Starbucks WiFi' requires no 
security.  No secrets needed.
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1050] Config: 
added 'ssid' value 'Starbucks WiFi'
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1050] Config: 
added 'scan_ssid' value '1'
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1050] Config: 
added 'bgscan' value 'simple:30:-80:86400'
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1050] Config: 
added 'key_mgmt' value 'NONE'
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1247] device 
(wlp0s20f3): supplicant interface state: disabled -> inactive
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1247] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: disabled -> inactive
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1317] device 
(wlp0s20f3): supplicant interface state: inactive -> scanning
Dec 23 18:38:41 camp NetworkManager[7818]: <info>  [1577126321.1318] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: inactive -> scanning
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2316] device 
(wlp0s20f3): supplicant interface state: scanning -> authenticating
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2316] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: scanning -> 
authenticating
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2704] device 
(wlp0s20f3): supplicant interface state: authenticating -> associating
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2705] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: authenticating -> 
associating
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2838] device 
(wlp0s20f3): supplicant interface state: associating -> completed
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2838] device 
(wlp0s20f3): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. 
Connected to wireless network "Starbucks WiFi"
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2838] device 
(p2p-dev-wlp0s20f3): supplicant management interface state: associating -> 
completed
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2846] device 
(wlp0s20f3): state change: config -> ip-config (reason 'none', sys-iface-state: 
'managed')
Dec 23 18:38:44 camp NetworkManager[7818]: <info>  [1577126324.2852] dhcp4 
(wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1844] dhcp4 
(wlp0s20f3): state changed unknown -> bound
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1874] device 
(wlp0s20f3): state change: ip-config -> ip-check (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1959] device 
(wlp0s20f3): state change: ip-check -> secondaries (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1960] device 
(wlp0s20f3): state change: secondaries -> activated (reason 'none', 
sys-iface-state: 'managed')
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1964] manager: 
NetworkManager state is now CONNECTED_LOCAL
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1978] manager: 
NetworkManager state is now CONNECTED_SITE
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1979] policy: 
set 'Starbucks WiFi' (wlp0s20f3) as default for IPv4 routing and DNS
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1983] device 
(wlp0s20f3): Activation: successful, device activated.
Dec 23 18:38:47 camp NetworkManager[7818]: <info>  [1577126327.1989] manager: 
NetworkManager state is now CONNECTED_GLOBAL
Dec 23 19:08:45 camp NetworkManager[7818]: <info>  [1577128125.1764] dhcp4 
(wlp0s20f3): state changed bound -> bound

Attachment: signature.asc
Description: PGP signature

Reply via email to