V 2.118 does not connect to wifi (RPi 3)

Jellby · March 12, 2017, 1:26pm

I just updated 2.041 to 2.118 (through the web UI) on my RPi 3, and now it seems volumio cannot connect to my wifi (which was working flawlessly before, and is still working for other devices). I have the hostpot disabled (I have tried with it enabled too), and this is the output from “sudo journalctl -f” when I try to enable wifi and save (minus some parts at the beginning and end, to stay withing the maximum post length):

Mar 12 14:11:12 volumio wireless.js[7008]: dhclientstderr: dhcpcd[7063]: sending commands to master dhcpcd process Mar 12 14:11:12 volumio wpa_supplicant[7058]: Line 11: Invalid WEP key length 8 - this network block will be ignored Mar 12 14:11:12 volumio wpa_supplicant[7058]: Priority group 1 Mar 12 14:11:12 volumio wpa_supplicant[7058]: id=0 ssid='TP-LINK_0CDBF2' Mar 12 14:11:12 volumio wpa_supplicant[7058]: id=1 ssid='TP-LINK_0CDBF2' Mar 12 14:11:12 volumio wpa_supplicant[7058]: rfkill: initial event: idx=0 type=1 op=0 soft=0 hard=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: rfkill: initial event: idx=1 type=2 op=0 soft=0 hard=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Using driver-based roaming Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: TDLS supported Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported cipher 00-0f-ac:1 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported cipher 00-0f-ac:5 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported cipher 00-0f-ac:2 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported cipher 00-0f-ac:4 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported cipher 00-0f-ac:6 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Using driver-based off-channel TX Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Supported vendor command: vendor_id=0x1018 subcmd=1 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Use separate P2P group interface (driver advertised support) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Enable multi-channel concurrent (driver advertised support) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: interface wlan0 in phy phy0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Set mode ifindex 3 iftype 2 (STATION) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Subscribe to mgmt frames with non-AP handle 0x5508b9f0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040a Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040b Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040c Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040d Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090a Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090b Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090c Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090d Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0409506f9a09 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=7f506f9a09 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0801 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040e Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=06 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0a07 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0a11 Mar 12 14:11:12 volumio wpa_supplicant[7058]: netlink: Operstate: ifindex=3 linkmode=1 (userspace-control), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: driver param='(null)' Mar 12 14:11:12 volumio wpa_supplicant[7058]: Add interface wlan0 to a new radio phy0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Regulatory information - country=00 Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 2402-2472 @ 40 MHz 20 mBm Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 2457-2482 @ 20 MHz 20 mBm (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 2474-2494 @ 20 MHz 20 mBm (no OFDM) (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 5170-5250 @ 80 MHz 20 mBm (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 5490-5730 @ 160 MHz 20 mBm (DFS) (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 5735-5835 @ 80 MHz 20 mBm (no IR) Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: 57240-63720 @ 2160 MHz 0 mBm Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Added 802.11b mode based on 802.11g information Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Do not indicate P2P_DEVICE support (p2p_device=1 driver param not specified) Mar 12 14:11:12 volumio kernel: brcmfmac: power management disabled Mar 12 14:11:12 volumio kernel: smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x4DE1 Mar 12 14:11:12 volumio wireless.js[7008]: dhclientchild process exited with code 0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wlan0: Own MAC address: b8:27:eb:ad:50:f2 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wlan0: RSN: flushing PMKID list in the driver Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Flush PMKIDs Mar 12 14:11:12 volumio wpa_supplicant[7058]: TDLS: TDLS operation supported by driver Mar 12 14:11:12 volumio wpa_supplicant[7058]: TDLS: Driver uses internal link setup Mar 12 14:11:12 volumio wpa_supplicant[7058]: wlan0: WPS: UUID based on MAC address: 0b93da8f-be70-542b-bf72-9d87cbd16ca2 Mar 12 14:11:12 volumio wpa_supplicant[7058]: EAPOL: SUPP_PAE entering state DISCONNECTED Mar 12 14:11:12 volumio wpa_supplicant[7058]: EAPOL: Supplicant port status: Unauthorized Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Skip set_supp_port(unauthorized) while not associated Mar 12 14:11:12 volumio wpa_supplicant[7058]: EAPOL: KEY_RX entering state NO_KEY_RECEIVE Mar 12 14:11:12 volumio wpa_supplicant[7058]: EAPOL: SUPP_BE entering state INITIALIZE Mar 12 14:11:12 volumio wpa_supplicant[7058]: EAP: EAP entering state DISABLED Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: Add operating class 81 Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: Channels - hexdump(len=11): 01 02 03 04 05 06 07 08 09 0a 0b Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: Own listen channel: 81:1 Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: Random operating channel: 81:1 Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: initialized Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11 Mar 12 14:11:12 volumio wpa_supplicant[7058]: P2P: cli_channels: Mar 12 14:11:12 volumio wpa_supplicant[7058]: wlan0: Added interface wlan0 Mar 12 14:11:12 volumio wpa_supplicant[7058]: wlan0: State: DISCONNECTED -> DISCONNECTED Mar 12 14:11:12 volumio wpa_supplicant[7058]: nl80211: Set wlan0 operstate 0->0 (DORMANT) Mar 12 14:11:12 volumio wpa_supplicant[7058]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:12 volumio wpa_supplicant[7058]: Daemonize.. Mar 12 14:11:12 volumio wpa_supplicant[7088]: random: Got 20/20 bytes from /dev/random Mar 12 14:11:12 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 operstate=2 linkmode=0 ifi_family=0 ifi_flags=0x1003 ([UP]) Mar 12 14:11:12 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP]) Mar 12 14:11:12 volumio wireless.js[7008]: wpa supplicantchild process exited with code 0 Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Starting delayed sched scan Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Use normal scan instead of sched_scan for initial scans (normal_scans=0) Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Setting scan request: 0.000000 sec Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: State: DISCONNECTED -> SCANNING Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Starting AP scan for wildcard SSID Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: Building WPS IE for Probe Request Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Version (hardcoded 0x10) Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Request Type Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Config Methods (2148) Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * UUID-E Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Primary Device Type Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * RF Bands (1) Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Association State Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Configuration Error (0) Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Device Password ID (0) Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Manufacturer Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Model Name Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Model Number Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Device Name Mar 12 14:11:12 volumio wpa_supplicant[7088]: WPS: * Version2 (0x20) Mar 12 14:11:12 volumio wpa_supplicant[7088]: P2P: * P2P IE header Mar 12 14:11:12 volumio wpa_supplicant[7088]: P2P: * Capability dev=25 group=00 Mar 12 14:11:12 volumio wpa_supplicant[7088]: P2P: * Listen Channel: Regulatory Class 81 Channel 1 Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Add radio work 'scan'@0x5508c2a8 Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: First radio work item in the queue - schedule start immediately Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Starting radio work 'scan'@0x5508c2a8 after 0.000612 second wait Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: nl80211: scan request Mar 12 14:11:12 volumio wpa_supplicant[7088]: Scan requested (ret=0) - scan timeout 10 seconds Mar 12 14:11:12 volumio wpa_supplicant[7088]: nl80211: Drv Event 33 (NL80211_CMD_TRIGGER_SCAN) received for wlan0 Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: nl80211: Scan trigger Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Event SCAN_STARTED (49) received Mar 12 14:11:12 volumio wpa_supplicant[7088]: wlan0: Own scan request started a scan in 0.000111 seconds Mar 12 14:11:13 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x1003 ([UP]) Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Drv Event 34 (NL80211_CMD_NEW_SCAN_RESULTS) received for wlan0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: nl80211: New scan results available Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Scan probed for SSID 'TP-LINK_0CDBF2' Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Scan probed for SSID '' Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Scan included frequencies: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Event SCAN_RESULTS (3) received Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Scan completed in 0.483612 seconds Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Received scan results (9 BSSes) Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Start scan result update 1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 0 BSSID e8:94:f6:0c:db:f2 SSID 'TP-LINK_0CDBF2' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 1 BSSID dc:53:7c:76:96:db SSID 'Kalle' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 2 BSSID 30:91:8f:d1:c3:f1 SSID 'TN_24GHz_D1C3F1' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 3 BSSID 12:7b:ef:b9:0d:cc SSID 'TN_private_RPV9CE' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 4 BSSID 40:4a:03:f9:ef:78 SSID 'TN_private_H34F7K' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 5 BSSID 34:e0:cf:c1:79:6a SSID '3Bredband_C1796A' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 6 BSSID e0:b9:e5:61:e0:23 SSID 'Telia-61E023' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 7 BSSID c4:ea:1d:f3:64:8b SSID 'TN_24GHz_F3648B' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: BSS: Add new id 8 BSSID fa:8f:ca:7e:30:27 SSID '' Mar 12 14:11:13 volumio wpa_supplicant[7088]: BSS: last_scan_res_used=9/32 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: New scan results available (own=1 ext=0) Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP e8:94:f6:0c:db:f2 type 0 added Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP dc:53:7c:76:96:db type 0 added Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP 30:91:8f:d1:c3:f1 type 0 added Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP e0:b9:e5:61:e0:23 type 0 added Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP c4:ea:1d:f3:64:8b type 0 added Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP[0] e8:94:f6:0c:db:f2 type=0 tries=0 last_attempt=-1 sec ago blacklist=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP[1] dc:53:7c:76:96:db type=0 tries=0 last_attempt=-1 sec ago blacklist=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP[2] 30:91:8f:d1:c3:f1 type=0 tries=0 last_attempt=-1 sec ago blacklist=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP[3] e0:b9:e5:61:e0:23 type=0 tries=0 last_attempt=-1 sec ago blacklist=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPS: AP[4] c4:ea:1d:f3:64:8b type=0 tries=0 last_attempt=-1 sec ago blacklist=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Radio work 'scan'@0x5508c2a8 done in 0.536390 seconds Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Selecting BSS from priority group 1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: 0: e8:94:f6:0c:db:f2 ssid='TP-LINK_0CDBF2' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-33 wps Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: selected based on RSN IE Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: selected BSS e8:94:f6:0c:db:f2 ssid='TP-LINK_0CDBF2' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Considering connect request: reassociate: 0 selected: e8:94:f6:0c:db:f2 bssid: 00:00:00:00:00:00 pending: 00:00:00:00:00:00 wpa_state: SCANNING ssid=0x5508b480 current_ssid=(nil) Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Request association with e8:94:f6:0c:db:f2 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=16): 00 0e 54 50 2d 4c 49 4e 4b 5f 30 43 44 42 46 32 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=3): 03 01 0b Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=8): 07 06 53 45 20 01 0d 14 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=3): 2a 01 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: RSN IE in EAPOL-Key - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=28): 33 1a ef 11 1b ff ff 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=24): 3d 16 0b 07 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=24): 34 16 0b 07 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: WMM Parameter Element - hexdump(len=24): 00 50 f2 02 01 01 87 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: TDLS: TDLS is allowed in the target BSS Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Add radio work 'connect'@0x550a0168 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: First radio work item in the queue - schedule start immediately Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Starting radio work 'connect'@0x550a0168 after 0.000646 second wait Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Trying to associate with SSID 'TP-LINK_0CDBF2' Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Cancelling scan request Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: clearing own WPA/RSN IE Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Automatic auth_alg selection: 0x1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: RSN: PMKSA cache search - network_ctx=0x5508b480 try_opportunistic=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: RSN: Search for BSSID e8:94:f6:0c:db:f2 Mar 12 14:11:13 volumio wpa_supplicant[7088]: RSN: No PMKSA cache entry found Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: RSN: using IEEE 802.11i/D9.0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: Selected mgmt group cipher 32 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: clearing AP WPA IE Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: using GTK CCMP Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: using PTK CCMP Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: using KEY_MGMT WPA-PSK Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: WPA: not using MGMT group cipher Mar 12 14:11:13 volumio wpa_supplicant[7088]: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: State: SCANNING -> ASSOCIATING Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Set wlan0 operstate 0->0 (DORMANT) Mar 12 14:11:13 volumio wpa_supplicant[7088]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_disable_max_amsdu: -1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_ampdu_factor: -1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_ampdu_density: -1 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_disable_ht40: 0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_disable_sgi: 0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: set_disable_ldpc: 0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Set mode ifindex 3 iftype 2 (STATION) Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Unsubscribe mgmt frames handle 0xdd803179 (mode change) Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Subscribe to mgmt frames with non-AP handle 0x5508b9f0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040a Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040b Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040c Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040d Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090a Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090b Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090c Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=090d Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0409506f9a09 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=7f506f9a09 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0801 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=040e Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=06 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0a07 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x5508b9f0 match=0a11 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Connect (ifindex=3) Mar 12 14:11:13 volumio wpa_supplicant[7088]: * bssid_hint=e8:94:f6:0c:db:f2 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * freq_hint=2462 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * IEs - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * WPA Versions 0x2 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * pairwise=0xfac04 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * group=0xfac04 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * akm=0xfac02 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * htcaps - hexdump(len=26): 63 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * htcaps_mask - hexdump(len=26): 63 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * vhtcaps - hexdump(len=12): 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * vhtcaps_mask - hexdump(len=12): 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:13 volumio wpa_supplicant[7088]: * Auth Type 0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: nl80211: Connect request send successfully Mar 12 14:11:13 volumio wpa_supplicant[7088]: wlan0: Setting authentication timeout: 10 sec 0 usec Mar 12 14:11:13 volumio wpa_supplicant[7088]: EAPOL: External notification - EAP success=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: EAPOL: External notification - EAP fail=0 Mar 12 14:11:13 volumio wpa_supplicant[7088]: EAPOL: External notification - portControl=Auto Mar 12 14:11:13 volumio wireless.js[7008]: trying... Mar 12 14:11:13 volumio sudo[7090]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:13 volumio sudo[7090]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:13 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:13 volumio wpa_supplicant[7088]: EAPOL: disable timer tick Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: RX EAPOL from e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Not associated - Delay processing of received EAPOL frame (state=ASSOCIATING bssid=00:00:00:00:00:00) Mar 12 14:11:14 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP]) Mar 12 14:11:14 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP]) Mar 12 14:11:14 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP]) Mar 12 14:11:14 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 operstate=5 linkmode=1 ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP]) Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Drv Event 46 (NL80211_CMD_CONNECT) received for wlan0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Connect event Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Associated on 2462 MHz Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Associated with e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Operating frequency for the associated BSS from scan results: 2462 MHz Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Event ASSOC (0) received Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Association info event Mar 12 14:11:14 volumio wpa_supplicant[7088]: req_ies - hexdump(len=105): 00 0e 54 50 2d 4c 49 4e 4b 5f 30 43 44 42 46 32 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 21 02 05 17 24 02 01 0d 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 2d 1a 21 00 1f ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 09 00 10 18 02 00 10 00 00 00 0b 10 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: resp_ies - hexdump(len=126): 01 08 82 84 8b 0c 12 96 18 24 32 04 30 48 60 6c 2d 1a af 01 1b ff ff 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 33 1a af 01 1b ff ff 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 3d 16 0b 07 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 16 0b 07 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 de ff a5 01 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=28): 33 1a af 01 1b ff ff 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=24): 3d 16 0b 07 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Unrecognized EAPOL-Key Key Data IE - hexdump(len=24): 34 16 0b 07 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: EAPOL-Key Key Data underflow (ie=222 len=255 pos=122) Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Key Data - hexdump(len=126): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: IEEE 802.11 element parse failed (id=222 elen=255 left=2) Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: freq=2462 MHz Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: Truncated IE in assoc_info - hexdump(len=4): de ff a5 01 Mar 12 14:11:14 volumio wpa_supplicant[7088]: FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0): Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: State: ASSOCIATING -> ASSOCIATED Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Set wlan0 operstate 0->0 (DORMANT) Mar 12 14:11:14 volumio wpa_supplicant[7088]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Associated to a new BSS: BSSID=e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: clearing AP WPA IE Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Associated with e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Association event - clear replay counter Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Clear old PTK Mar 12 14:11:14 volumio wpa_supplicant[7088]: TDLS: Remove peers on association Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - portEnabled=0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - portValid=0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - EAP success=0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - portEnabled=1 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_PAE entering state CONNECTING Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: enable timer tick Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_BE entering state IDLE Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Setting authentication timeout: 10 sec 0 usec Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Cancelling scan request Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Process pending EAPOL frame that was received just before association notification Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: RX EAPOL from e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Setting authentication timeout: 10 sec 0 usec Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: IEEE 802.1X RX: version=2 type=3 length=95 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: EAPOL-Key type=2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack) Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: key_length=16 key_data_length=0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_nonce - hexdump(len=32): 2f 87 49 2d a2 ed 69 a3 96 e4 de 38 31 20 04 c7 fb 09 9a e5 45 b2 d8 7e 31 f2 ec ca a5 03 57 24 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: RX message 1 of 4-Way Handshake from e8:94:f6:0c:db:f2 (ver=2) Mar 12 14:11:14 volumio wpa_supplicant[7088]: RSN: msg 1/4 key data - hexdump(len=0): Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Renewed SNonce - hexdump(len=32): 6c b8 eb 76 4f 55 da d6 70 e8 5a c1 d9 7b 4e e2 b3 6f be f7 e0 f7 63 76 1a 5a 93 07 6a 57 71 ab Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: PTK derivation - A1=b8:27:eb:ad:50:f2 A2=e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Nonce1 - hexdump(len=32): 6c b8 eb 76 4f 55 da d6 70 e8 5a c1 d9 7b 4e e2 b3 6f be f7 e0 f7 63 76 1a 5a 93 07 6a 57 71 ab Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Nonce2 - hexdump(len=32): 2f 87 49 2d a2 ed 69 a3 96 e4 de 38 31 20 04 c7 fb 09 9a e5 45 b2 d8 7e 31 f2 ec ca a5 03 57 24 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: PMK - hexdump(len=32): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: PTK - hexdump(len=48): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Sending EAPOL-Key 2/4 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: KCK - hexdump(len=16): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Derived Key MIC - hexdump(len=16): 48 29 32 25 bc ab b5 45 91 c2 90 86 b5 9f d1 c3 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Drv Event 36 (NL80211_CMD_REG_CHANGE) received for wlan0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Regulatory domain change Mar 12 14:11:14 volumio wpa_supplicant[7088]: * initiator=3 Mar 12 14:11:14 volumio wpa_supplicant[7088]: * type=0 Mar 12 14:11:14 volumio wpa_supplicant[7088]: * alpha2=SE Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Event CHANNEL_LIST_CHANGED (30) received Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=SE Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Regulatory information - country=SE (DFS-ETSI) Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: 2402-2482 @ 40 MHz 20 mBm Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: 5170-5250 @ 80 MHz 20 mBm Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: 5490-5710 @ 160 MHz 27 mBm (DFS) Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: 57000-66000 @ 2160 MHz 40 mBm Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Added 802.11b mode based on 802.11g information Mar 12 14:11:14 volumio wpa_supplicant[7088]: P2P: Add operating class 81 Mar 12 14:11:14 volumio wpa_supplicant[7088]: P2P: Channels - hexdump(len=13): 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d Mar 12 14:11:14 volumio wpa_supplicant[7088]: P2P: Update channel list Mar 12 14:11:14 volumio wpa_supplicant[7088]: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11,12,13 Mar 12 14:11:14 volumio wpa_supplicant[7088]: P2P: cli_channels: Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: RX EAPOL from e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: IEEE 802.1X RX: version=2 type=3 length=151 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: EAPOL-Key type=2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr) Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: key_length=16 key_data_length=56 Mar 12 14:11:14 volumio wpa_supplicant[7088]: replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_nonce - hexdump(len=32): 2f 87 49 2d a2 ed 69 a3 96 e4 de 38 31 20 04 c7 fb 09 9a e5 45 b2 d8 7e 31 f2 ec ca a5 03 57 24 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_rsc - hexdump(len=8): 82 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: key_mic - hexdump(len=16): db 28 b7 a5 cd 0b 63 bd 4c f0 48 2d 96 41 34 7a Mar 12 14:11:14 volumio wpa_supplicant[7088]: RSN: encrypted key data - hexdump(len=56): 28 ae 49 3a 78 6a b8 77 a6 b0 25 16 d0 a2 7e 72 a6 77 0d 8d dd d0 d3 6b 3d 5e f7 b7 a0 b4 48 99 8a ee d5 ad 63 04 69 02 4d 1f d6 6b e9 bd 30 c5 32 4c 5f 32 dd 92 f9 92 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: decrypted EAPOL-Key key data - hexdump(len=48): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: RX message 3 of 4-Way Handshake from e8:94:f6:0c:db:f2 (ver=2) Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: IE KeyData - hexdump(len=48): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 16 00 0f ac 01 01 00 8d a4 11 75 70 24 e9 ff e1 85 48 4b 89 fb 41 2f dd 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: RSN IE in EAPOL-Key - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Sending EAPOL-Key 4/4 Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: KCK - hexdump(len=16): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Derived Key MIC - hexdump(len=16): 79 70 8d 86 e2 f2 00 32 e0 47 80 98 c8 3e c9 37 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Installing PTK to the driver Mar 12 14:11:14 volumio wpa_supplicant[7088]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=3 addr=0x5508bfc0 key_idx=0 set_tx=1 seq_len=6 key_len=16 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: KEY_DATA - hexdump(len=16): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: KEY_SEQ - hexdump(len=6): 00 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: addr=e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - portValid=1 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE Mar 12 14:11:14 volumio wpa_supplicant[7088]: RSN: received GTK in pairwise handshake - hexdump(len=18): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: Group Key - hexdump(len=16): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16) Mar 12 14:11:14 volumio wpa_supplicant[7088]: WPA: RSC - hexdump(len=6): 82 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=3 addr=0x54ca5f4c key_idx=1 set_tx=0 seq_len=6 key_len=16 Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: KEY_DATA - hexdump(len=16): [REMOVED] Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: KEY_SEQ - hexdump(len=6): 82 00 00 00 00 00 Mar 12 14:11:14 volumio wpa_supplicant[7088]: broadcast key Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: WPA: Key negotiation completed with e8:94:f6:0c:db:f2 [PTK=CCMP GTK=CCMP] Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Cancelling authentication timeout Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: State: GROUP_HANDSHAKE -> COMPLETED Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: Radio work 'connect'@0x550a0168 done in 0.839206 seconds Mar 12 14:11:14 volumio wpa_supplicant[7088]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:94:f6:0c:db:f2 completed [id=0 id_str=] Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Set wlan0 operstate 0->1 (UP) Mar 12 14:11:14 volumio wpa_supplicant[7088]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=6 (IF_OPER_UP) Mar 12 14:11:14 volumio dhcpcd[520]: wlan0: carrier acquired Mar 12 14:11:14 volumio dhcpcd[520]: wlan0: adding address fe80::ba27:ebff:fead:50f2 Mar 12 14:11:14 volumio dhcpcd[520]: if_addaddress6: Permission denied Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - portValid=1 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: External notification - EAP success=1 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_PAE entering state AUTHENTICATING Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_BE entering state SUCCESS Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAP: EAP entering state DISABLED Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_PAE entering state AUTHENTICATED Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: Supplicant port status: Authorized Mar 12 14:11:14 volumio wpa_supplicant[7088]: nl80211: Set supplicant port authorized for e8:94:f6:0c:db:f2 Mar 12 14:11:14 volumio dhcpcd[520]: wlan0: IAID eb:ad:50:f2 Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL: SUPP_BE entering state IDLE Mar 12 14:11:14 volumio wpa_supplicant[7088]: EAPOL authentication completed - result=SUCCESS Mar 12 14:11:14 volumio wpa_supplicant[7088]: RTM_NEWLINK: ifi_index=3 ifname=wlan0 operstate=6 linkmode=1 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) Mar 12 14:11:14 volumio kernel: cfg80211: Regulatory domain changed to country: SE Mar 12 14:11:14 volumio kernel: cfg80211: DFS Master region: ETSI Mar 12 14:11:14 volumio kernel: cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time) Mar 12 14:11:14 volumio kernel: cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A) Mar 12 14:11:14 volumio kernel: cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A) Mar 12 14:11:14 volumio kernel: cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s) Mar 12 14:11:14 volumio kernel: cfg80211: (5490000 KHz - 5710000 KHz @ 160000 KHz), (N/A, 2700 mBm), (0 s) Mar 12 14:11:14 volumio kernel: cfg80211: (57000000 KHz - 66000000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A) Mar 12 14:11:14 volumio wireless.js[7008]: trying... Mar 12 14:11:14 volumio sudo[7098]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:14 volumio sudo[7098]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:14 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:14 volumio dhcpcd[520]: wlan0: rebinding lease of 192.168.10.211 Mar 12 14:11:14 volumio dhcpcd[520]: wlan0: soliciting an IPv6 router Mar 12 14:11:15 volumio wireless.js[7008]: trying... Mar 12 14:11:15 volumio sudo[7103]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:15 volumio sudo[7103]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:15 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:15 volumio ntpd[897]: Deleting interface #15 eth0, 192.168.10.136#123, interface stats: received=71, sent=72, dropped=0, active_time=1032 secs Mar 12 14:11:15 volumio ntpd[897]: 194.71.144.71 interface 192.168.10.136 -> (none) Mar 12 14:11:15 volumio ntpd[897]: 193.228.143.24 interface 192.168.10.136 -> (none) Mar 12 14:11:15 volumio ntpd[897]: 193.228.143.14 interface 192.168.10.136 -> (none) Mar 12 14:11:15 volumio ntpd[897]: 192.36.143.130 interface 192.168.10.136 -> (none) Mar 12 14:11:15 volumio ntpd[897]: peers refreshed Mar 12 14:11:16 volumio wpa_supplicant[7088]: EAPOL: startWhen --> 0 Mar 12 14:11:16 volumio wpa_supplicant[7088]: EAPOL: disable timer tick Mar 12 14:11:16 volumio dhcpcd[1003]: eth0: probing for an IPv4LL address Mar 12 14:11:16 volumio wireless.js[7008]: trying... Mar 12 14:11:16 volumio dhcpcd[1003]: eth0: DHCP lease expired Mar 12 14:11:16 volumio sudo[7108]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:16 volumio sudo[7108]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:16 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:16 volumio dhcpcd[1003]: eth0: soliciting a DHCP lease Mar 12 14:11:16 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.22.74 Mar 12 14:11:16 volumio dhcpcd[1003]: eth0: offered 192.168.10.136 from 192.168.10.1 Mar 12 14:11:17 volumio wireless.js[7008]: trying... Mar 12 14:11:17 volumio sudo[7122]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:17 volumio sudo[7122]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:17 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:17 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.138.44 Mar 12 14:11:18 volumio wireless.js[7008]: trying... Mar 12 14:11:18 volumio sudo[7127]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:18 volumio sudo[7127]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:18 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:18 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.117.166 Mar 12 14:11:19 volumio dhcpcd[520]: wlan0: leased 192.168.10.211 for 43200 seconds Mar 12 14:11:19 volumio avahi-daemon[1393]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.211. Mar 12 14:11:19 volumio avahi-daemon[1393]: New relevant interface wlan0.IPv4 for mDNS. Mar 12 14:11:19 volumio dhcpcd[520]: wlan0: adding route to 192.168.10.0/24 Mar 12 14:11:19 volumio dhcpcd[520]: wlan0: adding default route via 192.168.10.1 Mar 12 14:11:19 volumio avahi-daemon[1393]: Registering new address record for 192.168.10.211 on wlan0.IPv4. Mar 12 14:11:19 volumio wireless.js[7008]: trying... Mar 12 14:11:19 volumio sudo[7156]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:19 volumio sudo[7156]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:19 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:19 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.87.254 Mar 12 14:11:20 volumio dhcpcd[520]: eth0: leased 192.168.10.136 for 43200 seconds Mar 12 14:11:20 volumio dhcpcd[520]: eth0: adding route to 192.168.10.0/24 Mar 12 14:11:20 volumio avahi-daemon[1393]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.10.136. Mar 12 14:11:20 volumio avahi-daemon[1393]: New relevant interface eth0.IPv4 for mDNS. Mar 12 14:11:20 volumio dhcpcd[520]: eth0: adding default route via 192.168.10.1 Mar 12 14:11:20 volumio avahi-daemon[1393]: Registering new address record for 192.168.10.136 on eth0.IPv4. Mar 12 14:11:20 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 192.168.10.136 Mar 12 14:11:20 volumio volumio[1324]: Discovery: adding 4b76747a-7e19-49fe-8de7-0d4caa1d69c2 Mar 12 14:11:20 volumio volumio[1324]: info: mDNS: Found device Volumio Mar 12 14:11:20 volumio volumio[1324]: Discovery: this is already registered, 4b76747a-7e19-49fe-8de7-0d4caa1d69c2 Mar 12 14:11:20 volumio volumio[1324]: info: mDNS: Found device Volumio Mar 12 14:11:20 volumio wireless.js[7008]: trying... Mar 12 14:11:20 volumio sudo[7187]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:20 volumio sudo[7187]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:20 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.167.77 Mar 12 14:11:20 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:21 volumio dhcpcd[1003]: eth0: soliciting a DHCP lease Mar 12 14:11:21 volumio volumio[1324]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Mar 12 14:11:21 volumio sudo[7192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Mar 12 14:11:21 volumio sudo[7192]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 12 14:11:21 volumio volumio[6754]: :2:src/ohmetacache.cxx:122::dmcacheSaveWorker: can't get task from queue Mar 12 14:11:21 volumio volumio[6754]: :3:/usr/include/libupnpp/workqueue.h:193::SaveQueue: tasks 0 nowakes 0 wsleeps 1 csleeps 0 Mar 12 14:11:21 volumio mpd[570]: client: [11] closed Mar 12 14:11:21 volumio sudo[7192]: pam_unix(sudo:session): session closed for user root Mar 12 14:11:21 volumio sudo[7205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 12 14:11:21 volumio sudo[7205]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 12 14:11:21 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Mar 12 14:11:21 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 12 14:11:21 volumio sudo[7205]: pam_unix(sudo:session): session closed for user root Mar 12 14:11:21 volumio volumio[1324]: info: Upmpdcli Daemon Started Mar 12 14:11:21 volumio mpd[570]: client: [12] opened from ::ffff:127.0.0.1:41116 Mar 12 14:11:21 volumio ntpd[897]: Listen normally on 24 eth0 192.168.10.136 UDP 123 Mar 12 14:11:21 volumio ntpd[897]: Listen normally on 25 wlan0 192.168.10.211 UDP 123 Mar 12 14:11:21 volumio ntpd[897]: peers refreshed Mar 12 14:11:21 volumio dhcpcd[1003]: eth0: hardware address b8:27:eb:ad:50:f2 claims 169.254.54.130 Mar 12 14:11:21 volumio wireless.js[7008]: trying... Mar 12 14:11:21 volumio sudo[7225]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:21 volumio sudo[7225]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:21 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:22 volumio dhcpcd[1003]: eth0: leased 192.168.10.136 for 43200 seconds Mar 12 14:11:22 volumio dhcpcd[520]: eth0: removing route to 192.168.10.0/24 Mar 12 14:11:22 volumio dhcpcd[1003]: eth0: adding route to 192.168.10.0/24 Mar 12 14:11:22 volumio dhcpcd[1003]: eth0: adding default route via 192.168.10.1 Mar 12 14:11:22 volumio dhcpcd[520]: eth0: removing default route via 192.168.10.1 Mar 12 14:11:22 volumio dhcpcd[1003]: eth0: removing route to 192.168.10.0/24 Mar 12 14:11:22 volumio dhcpcd[1003]: eth0: removing default route via 192.168.10.1 Mar 12 14:11:22 volumio wireless.js[7008]: trying... Mar 12 14:11:22 volumio sudo[7250]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:22 volumio sudo[7250]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:22 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:23 volumio wireless.js[7008]: trying... Mar 12 14:11:23 volumio sudo[7256]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:23 volumio sudo[7256]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:23 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:24 volumio wireless.js[7008]: trying... Mar 12 14:11:24 volumio sudo[7261]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:24 volumio sudo[7261]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:24 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:25 volumio wireless.js[7008]: trying... Mar 12 14:11:26 volumio sudo[7266]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:26 volumio sudo[7266]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:26 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:27 volumio wireless.js[7008]: trying... Mar 12 14:11:27 volumio sudo[7272]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:27 volumio sudo[7272]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:27 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:28 volumio wireless.js[7008]: trying... Mar 12 14:11:28 volumio sudo[7277]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:28 volumio sudo[7277]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:28 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:29 volumio wireless.js[7008]: trying... Mar 12 14:11:29 volumio sudo[7282]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:29 volumio sudo[7282]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:29 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:30 volumio wireless.js[7008]: trying... Mar 12 14:11:30 volumio sudo[7287]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:30 volumio sudo[7287]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:30 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:31 volumio wireless.js[7008]: trying... Mar 12 14:11:31 volumio sudo[7292]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:31 volumio sudo[7292]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:31 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:32 volumio wireless.js[7008]: trying... Mar 12 14:11:32 volumio sudo[7297]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:32 volumio sudo[7297]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:32 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:33 volumio wireless.js[7008]: trying... Mar 12 14:11:33 volumio sudo[7302]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:33 volumio sudo[7302]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 12 14:11:33 volumio wireless.js[7008]: sudo: no tty present and no askpass program specified Mar 12 14:11:34 volumio wireless.js[7008]: Overtime, starting plan B Mar 12 14:11:34 volumio wireless.js[7008]: killing: kill `pgrep -f "^/usr/bin/sudo"` || true Mar 12 14:11:34 volumio wireless.js[7008]: killing: kill `pgrep -f "^wpa_supplicant"` || true Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Removing interface wlan0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Request to deauthenticate - bssid=e8:94:f6:0c:db:f2 pending_bssid=00:00:00:00:00:00 reason=3 state=COMPLETED Mar 12 14:11:34 volumio wpa_supplicant[7088]: TDLS: Tear down peers Mar 12 14:11:34 volumio wpa_supplicant[7088]: wpa_driver_nl80211_disconnect(reason_code=3) Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Event DEAUTH (12) received Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Deauthentication notification Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: * reason 3 (locally generated) Mar 12 14:11:34 volumio wpa_supplicant[7088]: Deauthentication frame IE(s) - hexdump(len=0): [NULL] Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e8:94:f6:0c:db:f2 reason=3 locally_generated=1 Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Auto connect disabled: do not try to re-connect Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Ignore connection failure indication since interface has been put into disconnected state Mar 12 14:11:34 volumio wpa_supplicant[7088]: TDLS: Remove peers on disassociation Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: Disconnect event - remove keys Mar 12 14:11:34 volumio wpa_supplicant[7088]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=0x5508aa48 key_idx=0 set_tx=0 seq_len=0 key_len=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: addr=e8:94:f6:0c:db:f2 Mar 12 14:11:34 volumio dhcpcd[520]: wlan0: carrier lost Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: State: COMPLETED -> DISCONNECTED Mar 12 14:11:34 volumio wpa_supplicant[7088]: nl80211: Set wlan0 operstate 1->0 (DORMANT) Mar 12 14:11:34 volumio wpa_supplicant[7088]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: External notification - portEnabled=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: SUPP_PAE entering state DISCONNECTED Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: Supplicant port status: Unauthorized Mar 12 14:11:34 volumio wpa_supplicant[7088]: nl80211: Skip set_supp_port(unauthorized) while not associated Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: SUPP_BE entering state INITIALIZE Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: External notification - portValid=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: External notification - EAP success=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: wlan0: State: DISCONNECTED -> DISCONNECTED Mar 12 14:11:34 volumio wpa_supplicant[7088]: nl80211: Set wlan0 operstate 0->0 (DORMANT) Mar 12 14:11:34 volumio wpa_supplicant[7088]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT) Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: External notification - portEnabled=0 Mar 12 14:11:34 volumio wpa_supplicant[7088]: EAPOL: External notification - portValid=0

I wonder if these lines, repeated many times, are relevant:

Mar 12 14:11:13 volumio sudo[7090]: pam_unix(sudo:auth): conversation failed Mar 12 14:11:13 volumio sudo[7090]: pam_unix(sudo:auth): auth could not identify password for [volumio]

macmpi · March 12, 2017, 1:38pm

You may want first to start from a new 2.118 image: upgrading from 2.041 caused several problems (underlying system changes).

If problem persists:
On which wifi channel is your Home AP router?
Can you try setting it to channel #4?

You may check this thread if changing channel fixes the issue.

Jellby · March 12, 2017, 1:53pm

I’ve gone into /volumio/app/plugins/system_controller/network/wireless.js to find out what was giving the error lines I pointed out above, it’s this:

var SSID = execSync("/usr/bin/sudo /sbin/iwgetid -r", { uid: 1000, gid: 1000, encoding: 'utf8'});

I wondered if sudo was actually needed, and why this was failing while other sudo commands in the script seemed to work, maybe it’s the execSync… Anyway, I just tried removing the sudo:

var SSID = execSync("/sbin/iwgetid -r", { uid: 1000, gid: 1000, encoding: 'utf8'});

and lo and behold, now Volumio connects to the wifi as it should (the log I showed suggested it was connecting correctly, but for some reason disconnecting at the end).

I may try reflashing, but I don’t think this has anything to do channel #4; and if this is the only problem I encounter, I’m willing to live with my modifed wireless.js and save a reflash for the moment.

Any idea why this is failing now and it didn’t before? I have installed some extra packages, and might have run “apt-get upgrade” at some point (before I knew I shouldn’t), but it didn’t seem to break anything so far.

macmpi · March 12, 2017, 2:17pm

Interesting and a bit unexpected indeed.

But again, OTA to 2.118 does break several things.

…and this is also very risky and not advisable on Volumio.

That makes too many unknowns (and too specific setup) to the equation to figure-out what can be the root cause.
You’d probably need to endure a reflash to get more efficient support either on this issue, or on any eventual next ones…
Good luck.

chsims1 · March 12, 2017, 2:20pm

It makes problem solving very difficult when you are not using a standard Volumio installation. Just because ‘apt-get upgrade’ didn’t appear to have a detrimental effect previously, it doesn’t necessarily hold true for future changes in Volumio. In my opinion, you would be best served by a clean installation, and steer clear of ‘apt-get upgrade’ and ‘dist-upgrade’ (as you now know).

Edit: oops, macmpi beat me to it

indy500 · March 13, 2017, 7:02pm

The same problem for me, Wifi doesn’t connect. Fresh installation of Volumio 2.118

Jellby · March 13, 2017, 7:06pm

Same solution?

indy500 · March 13, 2017, 7:34pm

Sorry, yes the same solution

macmpi · March 13, 2017, 10:51pm

If problem persists on a newly flashed 2.118 image (let first boot take time, about 10mn), please check this thread: if same symptoms (channel #4 issue), I’ll try to help you there.