Nov 12 17:42:56 ivanpaul kernel: [ 556.137801] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.137807] CFG80211-ERROR) wl_notifier_change_state : wlan0:error (-1) Nov 12 17:42:56 ivanpaul kernel: [ 556.137814] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.137819] CFG80211-ERROR) wl_cfg80211_update_power_mode : wl_cfg80211_update_power_mode:error (-1) Nov 12 17:42:56 ivanpaul kernel: [ 556.137832] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.137947] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.137953] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.137959] CFGP2P-ERROR) wl_cfgp2p_disable_discovery : unable to set WL_P2P_DISC_ST_SCAN Nov 12 17:42:56 ivanpaul kernel: [ 556.137978] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.137987] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.137992] CFGP2P-ERROR) wl_cfgp2p_set_discovery : p2p_disc 0 error -1 Nov 12 17:42:56 ivanpaul kernel: [ 556.138000] CFG80211-ERROR) wl_cfgp2p_down : Clean up the p2p discovery IF Nov 12 17:42:56 ivanpaul kernel: [ 556.138008] wl_cfgp2p_del_p2p_disc_if: wdev: ffffffc0efc4b800, wdev->net: (null) Nov 12 17:42:56 ivanpaul kernel: [ 556.138020] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138031] CFGP2P-ERROR) wl_cfgp2p_disable_discovery : do nothing, not initialized Nov 12 17:42:56 ivanpaul kernel: [ 556.138036] Exit. P2P interface stopped Nov 12 17:42:56 ivanpaul kernel: [ 556.138095] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138252] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138257] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138333] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138407] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.138503] dhdsdio_rxglom (superframe): len 0x0010, rounded 0x0100, expect 0x0500 Nov 12 17:42:56 ivanpaul kernel: [ 556.138510] dhdsdio_rxfail: abort command, terminate frame, send NAK Nov 12 17:42:56 ivanpaul kernel: [ 556.138939] dhdsdio_rxglom (subframe 0): length mismatch: len 0x04a0, expect 0x0194 Nov 12 17:42:56 ivanpaul kernel: [ 556.138949] dhdsdio_rxfail: abort command, terminate frame, send NAK Nov 12 17:42:56 ivanpaul kernel: [ 556.139350] dhdsdio_rxglom (superframe): len 0x0010, rounded 0x0100, expect 0x0500 Nov 12 17:42:56 ivanpaul kernel: [ 556.139359] dhdsdio_rxfail: abort command, terminate frame, send NAK Nov 12 17:42:56 ivanpaul kernel: [ 556.139749] dhdsdio_rxglom (superframe): len 0x0bc0, rounded 0x0c00, expect 0x0500 Nov 12 17:42:56 ivanpaul kernel: [ 556.139758] dhdsdio_rxfail: abort command, terminate frame Nov 12 17:42:56 ivanpaul kernel: [ 556.139878] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140185] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140194] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140199] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140204] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140325] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140330] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140334] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140339] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140482] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140488] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140635] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140641] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140722] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140727] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140731] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140801] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.140806] dhd_rx_frame: net device is NOT registered yet. drop packet Nov 12 17:42:56 ivanpaul kernel: [ 556.150030] P2P interface unregistered Nov 12 17:42:56 ivanpaul kernel: [ 556.150060] CFGP2P-ERROR) wl_cfgp2p_deinit_priv : In Nov 12 17:42:56 ivanpaul kernel: [ 556.150076] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.150085] CFG80211-ERROR) wl_dongle_down : WLC_DOWN error (-1) Nov 12 17:42:56 ivanpaul kernel: [ 556.150101] dhd_tcpack_suppress_set: TCP ACK Suppress mode 1 -> mode 0 Nov 12 17:42:56 ivanpaul kernel: [ 556.150136] wl_android_wifi_off in 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.150141] wl_android_wifi_off in 2: g_wifi_on=1, on_failure=1 Nov 12 17:42:56 ivanpaul kernel: [ 556.150146] dhd_prot_ioctl : bus is down. we have nothing to do - bs: 2, has: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.150160] dhd_dbg_detach_pkt_monitor, 2204 Nov 12 17:42:56 ivanpaul kernel: [ 556.150166] dhd_bus_devreset: == Power OFF == Nov 12 17:42:56 ivanpaul kernel: [ 556.350275] sdioh_buffer_tofrom_bus: RX FAILED ffffffc0f145a220, addr=0x08000, pkt_len=32, ERR=-84 Nov 12 17:42:56 ivanpaul kernel: [ 556.350375] dhdsdio_readframes: RXHEADER FAILED: -35 Nov 12 17:42:56 ivanpaul kernel: [ 556.350385] dhdsdio_rxfail: abort command, terminate frame, send NAK Nov 12 17:42:56 ivanpaul kernel: [ 556.358603] dwmmc_rockchip fe310000.dwmmc: All phases work, using default phase 0. Nov 12 17:42:56 ivanpaul kernel: [ 556.358881] dhdsdio_isr : bus is down. we have nothing to do Nov 12 17:42:56 ivanpaul kernel: [ 556.358968] dhd_txglom_enable: enable 0 Nov 12 17:42:56 ivanpaul kernel: [ 556.358978] dhd_conf_set_txglom_params: txglom_mode=copy Nov 12 17:42:56 ivanpaul kernel: [ 556.358986] dhd_conf_set_txglom_params: txglomsize=0, deferred_tx_len=0 Nov 12 17:42:56 ivanpaul kernel: [ 556.358993] dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Nov 12 17:42:56 ivanpaul kernel: [ 556.359000] dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=-1 Nov 12 17:42:56 ivanpaul kernel: [ 556.359010] dhd_bus_devreset: WLAN OFF DONE Nov 12 17:42:56 ivanpaul kernel: [ 556.359155] wifi_platform_set_power = 0 Nov 12 17:42:56 ivanpaul kernel: [ 556.359162] ======== PULL WL_REG_ON(-1) LOW! ======== Nov 12 17:42:56 ivanpaul kernel: [ 556.359171] [WLAN_RFKILL]: rockchip_wifi_power: 0 Nov 12 17:42:56 ivanpaul kernel: [ 556.359208] [WLAN_RFKILL]: wifi shut off power. Nov 12 17:42:56 ivanpaul kernel: [ 556.359213] wl_android_wifi_off out Nov 12 17:42:56 ivanpaul kernel: [ 556.359222] wl_ext_iapsta_dettach_netdev: ifidx=0 Nov 12 17:42:56 ivanpaul kernel: [ 556.359277] dhd_stop: Exit Nov 12 17:42:56 ivanpaul wpa_supplicant[503]: wlan0: CTRL-EVENT-DISCONNECTED bssid=94:4a:0c:e5:65:fc reason=3 locally_generated=1 Nov 12 17:42:56 ivanpaul kernel: [ 556.360123] CFG80211-ERROR) wl_cfg80211_hang : In : chip crash eventing, reason=0x8001 Nov 12 17:42:56 ivanpaul dhclient[834]: receive_packet failed on wlan0: Network is down Nov 12 17:42:56 ivanpaul dhcpcd[439]: wlan0: carrier lost Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Interface wlan0.IPv6 no longer relevant for mDNS. Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee. Nov 12 17:42:56 ivanpaul kernel: [ 556.372409] dhd_open: Enter ffffffc0efc3b000 Nov 12 17:42:56 ivanpaul kernel: [ 556.372426] dhd_open : no mutex held. set lock Nov 12 17:42:56 ivanpaul kernel: [ 556.372445] Nov 12 17:42:56 ivanpaul kernel: [ 556.372445] Dongle Host Driver, version 1.579.77.41.10 (r) Nov 12 17:42:56 ivanpaul kernel: [ 556.372453] wl_ext_iapsta_attach_netdev: ifidx=0, bssidx=0 Nov 12 17:42:56 ivanpaul NetworkManager[377]: [1573580576.3608] device (wlan0): supplicant interface state: completed -> disabled Nov 12 17:42:56 ivanpaul kernel: [ 556.372459] wl_android_wifi_on in 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.372464] wl_android_wifi_on in 2: g_wifi_on=0 Nov 12 17:42:56 ivanpaul kernel: [ 556.372470] wifi_platform_set_power = 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.372475] ======== PULL WL_REG_ON(-1) HIGH! ======== Nov 12 17:42:56 ivanpaul kernel: [ 556.372482] [WLAN_RFKILL]: rockchip_wifi_power: 1 Nov 12 17:42:56 ivanpaul kernel: [ 556.372489] [WLAN_RFKILL]: wifi turn on power. -1 Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Interface wlan0.IPv4 no longer relevant for mDNS. Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.189. Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Withdrawing address record for fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee on wlan0. Nov 12 17:42:56 ivanpaul avahi-daemon[342]: Withdrawing address record for 192.168.2.189 on wlan0. Nov 12 17:42:56 ivanpaul dhcpcd[439]: wlan0: adding route to fd91:dab6:a2b2:1::/64 Nov 12 17:42:56 ivanpaul dhcpcd[439]: wlan0: deleting route to fd91:dab6:a2b2:1::/64 Nov 12 17:42:56 ivanpaul kernel: [ 556.672946] sdio_reset_comm(): Nov 12 17:42:56 ivanpaul kernel: [ 556.701096] mmc_host mmc2: Bus speed (slot 0) = 400000Hz (slot req 400000Hz, actual 400000HZ div = 0) Nov 12 17:42:56 ivanpaul kernel: [ 556.718021] mmc_host mmc2: Bus speed (slot 0) = 100000Hz (slot req 100000Hz, actual 100000HZ div = 0) Nov 12 17:42:56 ivanpaul kernel: [ 556.780663] sdio_read_cis: 1 callbacks suppressed Nov 12 17:42:56 ivanpaul kernel: [ 556.780681] mmc2: queuing unknown CIS tuple 0x80 (2 bytes) Nov 12 17:42:56 ivanpaul kernel: [ 556.787300] mmc2: queuing unknown CIS tuple 0x80 (3 bytes) Nov 12 17:42:56 ivanpaul kernel: [ 556.793580] mmc2: queuing unknown CIS tuple 0x80 (3 bytes) Nov 12 17:42:56 ivanpaul kernel: [ 556.805428] mmc2: queuing unknown CIS tuple 0x80 (7 bytes) Nov 12 17:42:56 ivanpaul kernel: [ 556.819321] mmc2: queuing unknown CIS tuple 0x81 (9 bytes) Nov 12 17:42:57 ivanpaul kernel: [ 557.042552] mmc_host mmc2: Bus speed (slot 0) = 84500000Hz (slot req 90000000Hz, actual 84500000HZ div = 0) Nov 12 17:42:57 ivanpaul kernel: [ 557.057816] dwmmc_rockchip fe310000.dwmmc: All phases work, using default phase 0. Nov 12 17:42:57 ivanpaul kernel: [ 557.057873] sdioh_start: set sd_f2_blocksize 256 Nov 12 17:42:57 ivanpaul kernel: [ 557.058210] Nov 12 17:42:57 ivanpaul kernel: [ 557.058210] Nov 12 17:42:57 ivanpaul kernel: [ 557.058210] dhd_bus_devreset: == WLAN ON == Nov 12 17:42:57 ivanpaul kernel: [ 557.058304] F1 signature read @0x18000000=0x15294345 Nov 12 17:42:57 ivanpaul kernel: [ 557.071563] dwmmc_rockchip fe310000.dwmmc: All phases work, using default phase 0. Nov 12 17:42:57 ivanpaul kernel: [ 557.071608] bcmsdh_sdmmc: Failed to Read word F1:@0x0a15c=ffffffff, Err: 0xffffffac Nov 12 17:42:57 ivanpaul kernel: [ 557.071617] bcmsdh_reg_read: error reading addr 0xa15c size 4 Nov 12 17:42:57 ivanpaul kernel: [ 557.093998] Reached end of erom without finding END Nov 12 17:42:57 ivanpaul kernel: [ 557.094053] si_doattach: could not find any cores Nov 12 17:42:57 ivanpaul kernel: [ 557.094077] dhdsdio_probe_attach: si_attach failed! Nov 12 17:42:57 ivanpaul kernel: [ 557.094093] dhd_net_bus_devreset: dhd_bus_devreset: -35 Nov 12 17:42:57 ivanpaul kernel: [ 557.094107] dhd_wl_ioctl: returning as busstate=0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094117] dhd_dbg_detach_pkt_monitor, 2204 Nov 12 17:42:57 ivanpaul kernel: [ 557.094127] dhd_net_bus_devreset: dhd_bus_devreset: -35 Nov 12 17:42:57 ivanpaul kernel: [ 557.094200] wifi_platform_set_power = 0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094210] ======== PULL WL_REG_ON(-1) LOW! ======== Nov 12 17:42:57 ivanpaul kernel: [ 557.094220] [WLAN_RFKILL]: rockchip_wifi_power: 0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094262] [WLAN_RFKILL]: wifi shut off power. Nov 12 17:42:57 ivanpaul kernel: [ 557.094269] wl_android_wifi_on: Failed Nov 12 17:42:57 ivanpaul kernel: [ 557.094278] dhd_open : wl_android_wifi_on failed (-35) Nov 12 17:42:57 ivanpaul kernel: [ 557.094292] dhd_stop: Enter ffffffc0efc3b000 Nov 12 17:42:57 ivanpaul kernel: [ 557.094297] wl_android_wifi_off in 1 Nov 12 17:42:57 ivanpaul kernel: [ 557.094302] wl_android_wifi_off in 2: g_wifi_on=0, on_failure=1 Nov 12 17:42:57 ivanpaul kernel: [ 557.094308] dhd_wl_ioctl: returning as busstate=0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094314] dhd_dbg_detach_pkt_monitor, 2204 Nov 12 17:42:57 ivanpaul kernel: [ 557.094318] dhd_net_bus_devreset: dhd_bus_devreset: -35 Nov 12 17:42:57 ivanpaul kernel: [ 557.094571] wifi_platform_set_power = 0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094582] ======== PULL WL_REG_ON(-1) LOW! ======== Nov 12 17:42:57 ivanpaul kernel: [ 557.094586] [WLAN_RFKILL]: rockchip_wifi_power: 0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094608] [WLAN_RFKILL]: wifi shut off power. Nov 12 17:42:57 ivanpaul kernel: [ 557.094614] wl_android_wifi_off out Nov 12 17:42:57 ivanpaul kernel: [ 557.094623] wl_ext_iapsta_dettach_netdev: ifidx=0 Nov 12 17:42:57 ivanpaul kernel: [ 557.094670] dhd_stop: Exit Nov 12 17:42:57 ivanpaul kernel: [ 557.094676] dhd_open : the lock is released. Nov 12 17:42:57 ivanpaul kernel: [ 557.094680] dhd_open: Exit ret=-1 Nov 12 17:42:57 ivanpaul NetworkManager[377]: [1573580577.0872] platform-linux: do-change-link[2]: failure changing link: failure 1 (Operation not permitted) Nov 12 17:42:57 ivanpaul NetworkManager[377]: [1573580577.0875] device (wlan0): interface wlan0 not up for IP configuration Nov 12 17:42:58 ivanpaul ntpd[533]: Deleting interface #5 wlan0, fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee#123, interface stats: received=0, sent=1, dropped=0, active_time=528 secs Nov 12 17:42:58 ivanpaul ntpd[533]: Deleting interface #6 wlan0, fe80::c047:60a:2557:1879%2#123, interface stats: received=0, sent=0, dropped=0, active_time=528 secs Nov 12 17:42:58 ivanpaul ntpd[533]: Deleting interface #7 wlan0, 192.168.2.189#123, interface stats: received=236, sent=248, dropped=0, active_time=523 secs Nov 12 17:42:58 ivanpaul ntpd[533]: 94.130.184.193 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 217.144.138.234 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 159.69.150.81 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 176.9.84.209 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 144.76.76.107 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 35.158.196.249 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 192.53.103.108 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 162.159.200.1 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 129.250.35.251 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 37.58.57.238 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 136.243.102.134 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 162.159.200.123 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 78.46.204.247 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 217.91.44.17 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 213.239.239.164 local addr 192.168.2.189 -> Nov 12 17:42:58 ivanpaul ntpd[533]: 94.130.49.186 local addr 192.168.2.189 -> Nov 12 17:43:03 ivanpaul wpa_supplicant[503]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-100 retry=1 Nov 12 17:44:32 ivanpaul upowerd[926]: energy_full (37.945600) is greater than energy_full_design (0.000000) Nov 12 17:45:03 ivanpaul wpa_supplicant[503]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-100 retry=1 Nov 12 17:45:10 ivanpaul NetworkManager[377]: [1573580710.8470] manager: sleep requested (sleeping: no enabled: yes) Nov 12 17:45:10 ivanpaul NetworkManager[377]: [1573580710.8471] manager: sleeping... Nov 12 17:45:10 ivanpaul NetworkManager[377]: [1573580710.8475] manager: NetworkManager state is now ASLEEP Nov 12 17:45:10 ivanpaul dbus[347]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Nov 12 17:45:10 ivanpaul systemd[1]: Reached target Sleep. Nov 12 17:45:10 ivanpaul systemd[1]: Starting Suspend... Nov 12 17:45:10 ivanpaul systemd[1]: Starting Network Manager Script Dispatcher Service... Nov 12 17:45:10 ivanpaul systemd-sleep[2475]: Suspending system... Nov 12 17:45:10 ivanpaul kernel: [ 690.901894] PM: suspend entry 2019-11-12 17:45:10.892677168 UTC Nov 12 17:45:10 ivanpaul dbus[347]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Nov 12 17:45:10 ivanpaul systemd[1]: Started Network Manager Script Dispatcher Service. Nov 12 17:45:10 ivanpaul nm-dispatcher: req:1 'connectivity-change': new request (2 scripts) Nov 12 17:45:10 ivanpaul nm-dispatcher: req:1 'connectivity-change': start running ordered scripts... Nov 12 17:45:10 ivanpaul kernel: [ 690.901931] PM: Syncing filesystems ... done. Nov 12 17:45:10 ivanpaul kernel: [ 690.941009] PM: Preparing system for sleep (mem) Nov 12 18:02:36 ivanpaul kernel: [ 690.941411] Freezing user space processes ... (elapsed 0.003 seconds) done. Nov 12 18:02:36 ivanpaul kernel: [ 690.944896] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Nov 12 18:02:36 ivanpaul kernel: [ 690.946806] PM: Suspending system (mem) Nov 12 18:02:36 ivanpaul kernel: [ 690.946814] Suspending console(s) (use no_console_suspend to debug) Nov 12 18:02:36 ivanpaul kernel: [ 690.947028] [BT_RFKILL]: Enter rfkill_rk_pm_prepare Nov 12 18:02:36 ivanpaul kernel: [ 690.947030] [BT_RFKILL]: Disable UART_RTS Nov 12 18:02:36 ivanpaul kernel: [ 690.947079] [BT_RFKILL]: enable irq for bt wakeup host Nov 12 18:02:36 ivanpaul kernel: [ 690.951277] bcmsdh_sdmmc_suspend Enter func->num=2 Nov 12 18:02:36 ivanpaul kernel: [ 690.951282] dhdsdio_suspend Enter Nov 12 18:02:36 ivanpaul kernel: [ 690.951286] bcmsdh_sdmmc_suspend Exit Nov 12 18:02:36 ivanpaul kernel: [ 690.951293] bcmsdh_sdmmc_suspend Enter func->num=1 Nov 12 18:02:36 ivanpaul kernel: [ 691.036024] [WLAN_RFKILL]: Enter rfkill_wlan_suspend Nov 12 18:02:36 ivanpaul kernel: [ 691.159386] rockchip-dmc dmc: failed to get dfi event Nov 12 18:02:36 ivanpaul kernel: [ 691.160955] PM: suspend of devices complete after 213.209 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.164817] LDO_REG2: No configuration Nov 12 18:02:36 ivanpaul kernel: [ 691.170901] PM: late suspend of devices complete after 3.705 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.173678] PM: noirq suspend of devices complete after 2.765 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.173684] Disabling non-boot CPUs ... Nov 12 18:02:36 ivanpaul kernel: [ 691.175287] CPU1: shutdown Nov 12 18:02:36 ivanpaul kernel: [ 691.185489] psci: Retrying again to check for CPU kill Nov 12 18:02:36 ivanpaul kernel: [ 691.185493] psci: CPU1 killed. Nov 12 18:02:36 ivanpaul kernel: [ 691.193760] CPU2: shutdown Nov 12 18:02:36 ivanpaul kernel: [ 691.204480] psci: Retrying again to check for CPU kill Nov 12 18:02:36 ivanpaul kernel: [ 691.204484] psci: CPU2 killed. Nov 12 18:02:36 ivanpaul kernel: [ 691.212403] CPU3: shutdown Nov 12 18:02:36 ivanpaul kernel: [ 691.222477] psci: Retrying again to check for CPU kill Nov 12 18:02:36 ivanpaul kernel: [ 691.222481] psci: CPU3 killed. Nov 12 18:02:36 ivanpaul kernel: [ 691.229830] CPU4: shutdown Nov 12 18:02:36 ivanpaul kernel: [ 691.240472] psci: Retrying again to check for CPU kill Nov 12 18:02:36 ivanpaul kernel: [ 691.240476] psci: CPU4 killed. Nov 12 18:02:36 ivanpaul kernel: [ 691.247326] CPU5: shutdown Nov 12 18:02:36 ivanpaul kernel: [ 691.257469] psci: Retrying again to check for CPU kill Nov 12 18:02:36 ivanpaul kernel: [ 691.257473] psci: CPU5 killed. Nov 12 18:02:36 ivanpaul kernel: [ 691.263024] Enabling non-boot CPUs ... Nov 12 18:02:36 ivanpaul kernel: [ 691.266553] Detected VIPT I-cache on CPU1 Nov 12 18:02:36 ivanpaul kernel: [ 691.266586] CPU1: found redistributor 1 region 0:0x00000000fef20000 Nov 12 18:02:36 ivanpaul kernel: [ 691.266640] CPU1: update cpu_capacity 401 Nov 12 18:02:36 ivanpaul kernel: [ 691.266644] CPU1: Booted secondary processor [410fd034] Nov 12 18:02:36 ivanpaul kernel: [ 691.267166] CPU1 is up Nov 12 18:02:36 ivanpaul kernel: [ 691.272559] Detected VIPT I-cache on CPU2 Nov 12 18:02:36 ivanpaul kernel: [ 691.272583] CPU2: found redistributor 2 region 0:0x00000000fef40000 Nov 12 18:02:36 ivanpaul kernel: [ 691.272620] CPU2: update cpu_capacity 401 Nov 12 18:02:36 ivanpaul kernel: [ 691.272624] CPU2: Booted secondary processor [410fd034] Nov 12 18:02:36 ivanpaul kernel: [ 691.273195] CPU2 is up Nov 12 18:02:36 ivanpaul kernel: [ 691.278791] Detected VIPT I-cache on CPU3 Nov 12 18:02:36 ivanpaul kernel: [ 691.278813] CPU3: found redistributor 3 region 0:0x00000000fef60000 Nov 12 18:02:36 ivanpaul kernel: [ 691.278852] CPU3: update cpu_capacity 401 Nov 12 18:02:36 ivanpaul kernel: [ 691.278855] CPU3: Booted secondary processor [410fd034] Nov 12 18:02:36 ivanpaul kernel: [ 691.279623] CPU3 is up Nov 12 18:02:36 ivanpaul kernel: [ 691.288030] Detected PIPT I-cache on CPU4 Nov 12 18:02:36 ivanpaul kernel: [ 691.288059] CPU4: found redistributor 100 region 0:0x00000000fef80000 Nov 12 18:02:36 ivanpaul kernel: [ 691.288118] CPU4: update cpu_capacity 1024 Nov 12 18:02:36 ivanpaul kernel: [ 691.288121] CPU4: Booted secondary processor [410fd082] Nov 12 18:02:36 ivanpaul kernel: [ 691.289632] cpu cpu4: Looking up cpu-supply from device tree Nov 12 18:02:36 ivanpaul kernel: [ 691.291109] cpu cpu4: failed to find power_model node Nov 12 18:02:36 ivanpaul kernel: [ 691.291285] CPU4 is up Nov 12 18:02:36 ivanpaul kernel: [ 691.300355] Detected PIPT I-cache on CPU5 Nov 12 18:02:36 ivanpaul kernel: [ 691.300376] CPU5: found redistributor 101 region 0:0x00000000fefa0000 Nov 12 18:02:36 ivanpaul kernel: [ 691.300414] CPU5: update cpu_capacity 1024 Nov 12 18:02:36 ivanpaul kernel: [ 691.300417] CPU5: Booted secondary processor [410fd082] Nov 12 18:02:36 ivanpaul kernel: [ 691.302613] CPU5 is up Nov 12 18:02:36 ivanpaul kernel: [ 691.305488] PM: noirq resume of devices complete after 1.924 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.307534] PM: early resume of devices complete after 1.656 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.325647] rockchip-dmc dmc: failed to get dfi event Nov 12 18:02:36 ivanpaul kernel: [ 691.331268] rockchip-dmc dmc: failed to get dfi event Nov 12 18:02:36 ivanpaul kernel: [ 691.331302] rockchip-vop ff900000.vop: [drm:vop_crtc_enable] Update mode to 1920x1080p0, type: 14 Nov 12 18:02:36 ivanpaul kernel: [ 691.354908] rockchip-dp ff970000.edp: [drm:analogix_dp_link_start] Enable downspread on the sink Nov 12 18:02:36 ivanpaul kernel: [ 691.357976] rockchip-dp ff970000.edp: Link Training Clock Recovery success Nov 12 18:02:36 ivanpaul kernel: [ 691.359439] rockchip-dp ff970000.edp: Link Training success! Nov 12 18:02:36 ivanpaul kernel: [ 691.371721] rockchip-dmc dmc: failed to get dfi event Nov 12 18:02:36 ivanpaul kernel: [ 691.517863] [WLAN_RFKILL]: Enter rfkill_wlan_resume Nov 12 18:02:36 ivanpaul kernel: [ 691.521137] Suspended for 1044.489 seconds Nov 12 18:02:36 ivanpaul kernel: [ 691.542577] mmc_host mmc2: Bus speed (slot 0) = 84500000Hz (slot req 90000000Hz, actual 84500000HZ div = 0) Nov 12 18:02:36 ivanpaul kernel: [ 691.542686] bcmsdh_sdmmc_resume Enter func->num=1 Nov 12 18:02:36 ivanpaul kernel: [ 691.542693] bcmsdh_sdmmc_resume Enter func->num=2 Nov 12 18:02:36 ivanpaul kernel: [ 691.542697] dhdsdio_resume Enter Nov 12 18:02:36 ivanpaul kernel: [ 691.542700] bcmsdh_sdmmc_resume Exit Nov 12 18:02:36 ivanpaul kernel: [ 691.542786] cdn-dp fec00000.dp: [drm:cdn_dp_pd_event_work] Not connected. Disabling cdn Nov 12 18:02:36 ivanpaul kernel: [ 691.693158] PM: resume of devices complete after 385.533 msecs Nov 12 18:02:36 ivanpaul kernel: [ 691.697232] [BT_RFKILL]: Enter rfkill_rk_pm_complete Nov 12 18:02:36 ivanpaul kernel: [ 691.697235] [BT_RFKILL]: ** disable irq Nov 12 18:02:36 ivanpaul kernel: [ 691.697244] [BT_RFKILL]: Enable UART_RTS Nov 12 18:02:36 ivanpaul kernel: [ 691.697924] PM: Finishing wakeup. Nov 12 18:02:36 ivanpaul kernel: [ 691.697930] Restarting tasks ... Nov 12 18:02:36 ivanpaul kernel: [ 691.698273] usb 3-1: USB disconnect, device number 2 Nov 12 18:02:36 ivanpaul kernel: [ 691.700446] usb 1-1.2: USB disconnect, device number 3 Nov 12 18:02:36 ivanpaul kernel: [ 691.705510] done. Nov 12 18:02:36 ivanpaul kernel: [ 691.705686] PM: suspend exit 2019-11-12 18:02:36.186390373 UTC Nov 12 18:02:36 ivanpaul systemd[1]: Time has been changed Nov 12 18:02:36 ivanpaul systemd[1]: apt-daily.timer: Adding 5h 33min 126.591ms random time. Nov 12 18:02:36 ivanpaul systemd[1]: apt-daily-upgrade.timer: Adding 31min 47.690153s random time. Nov 12 18:02:36 ivanpaul systemd[610]: Time has been changed Nov 12 18:02:36 ivanpaul systemd[688]: Time has been changed Nov 12 18:02:36 ivanpaul systemd-sleep[2475]: System resumed. Nov 12 18:02:36 ivanpaul nm-dispatcher: req:2 'connectivity-change': new request (2 scripts) Nov 12 18:02:36 ivanpaul upowerd[926]: energy_full (39.445000) is greater than energy_full_design (0.000000) Nov 12 18:02:36 ivanpaul nm-dispatcher: req:2 'connectivity-change': start running ordered scripts... Nov 12 18:02:36 ivanpaul systemd[1]: Started Suspend. Nov 12 18:02:36 ivanpaul nm-dispatcher: req:3 'connectivity-change': new request (2 scripts) Nov 12 18:02:36 ivanpaul systemd[1]: sleep.target: Unit not needed anymore. Stopping. Nov 12 18:02:36 ivanpaul systemd[1]: Stopped target Sleep. Nov 12 18:02:36 ivanpaul systemd[1]: Reached target Suspend. Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2155] manager: wake requested (sleeping: yes enabled: yes) Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2155] manager: waking up... Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2157] device (wlan0): state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Nov 12 18:02:36 ivanpaul systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Nov 12 18:02:36 ivanpaul nm-dispatcher: req:3 'connectivity-change': start running ordered scripts... Nov 12 18:02:36 ivanpaul systemd[1]: Stopped target Suspend. Nov 12 18:02:36 ivanpaul upowerd[926]: energy_full (39.445000) is greater than energy_full_design (0.000000) Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2324] dhcp4 (wlan0): canceled DHCP transaction, DHCP client pid 834 Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2325] dhcp4 (wlan0): state changed bound -> done Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2333] dhcp6 (wlan0): canceled DHCP transaction Nov 12 18:02:36 ivanpaul upowerd[926]: energy_full (39.445000) is greater than energy_full_design (0.000000) Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2406] manager: NetworkManager state is now CONNECTED_GLOBAL Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2412] manager: NetworkManager state is now CONNECTED_SITE Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2425] manager: NetworkManager state is now CONNECTED_LOCAL Nov 12 18:02:36 ivanpaul upowerd[926]: energy_full (39.445000) is greater than energy_full_design (0.000000) Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.2428] manager: NetworkManager state is now DISCONNECTED Nov 12 18:02:36 ivanpaul upowerd[926]: energy_full (39.445000) is greater than energy_full_design (0.000000) Nov 12 18:02:36 ivanpaul wpa_supplicant[503]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Nov 12 18:02:36 ivanpaul kernel: [ 691.884918] usb 1-1.2: new high-speed USB device number 4 using ehci-platform Nov 12 18:02:36 ivanpaul wpa_supplicant[503]: Could not read interface p2p-dev-wlan0 flags: No such device Nov 12 18:02:36 ivanpaul NetworkManager[377]: [1573581756.3878] device (wlan0): state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Nov 12 18:02:36 ivanpaul kernel: [ 691.909681] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready Nov 12 18:02:36 ivanpaul kernel: [ 691.909944] dhd_open: Enter ffffffc0efc3b000 Nov 12 18:02:36 ivanpaul nm-dispatcher: req:4 'down' [wlan0]: new request (2 scripts) Nov 12 18:02:36 ivanpaul kernel: [ 691.909952] dhd_open : no mutex held. set lock Nov 12 18:02:36 ivanpaul kernel: [ 691.909968] Nov 12 18:02:36 ivanpaul kernel: [ 691.909968] Dongle Host Driver, version 1.579.77.41.10 (r) Nov 12 18:02:36 ivanpaul kernel: [ 691.909976] wl_ext_iapsta_attach_netdev: ifidx=0, bssidx=0 Nov 12 18:02:36 ivanpaul kernel: [ 691.909983] wl_android_wifi_on in 1 Nov 12 18:02:36 ivanpaul kernel: [ 691.910653] wl_android_wifi_on in 2: g_wifi_on=0 Nov 12 18:02:36 ivanpaul kernel: [ 691.910665] wifi_platform_set_power = 1 Nov 12 18:02:36 ivanpaul kernel: [ 691.910672] ======== PULL WL_REG_ON(-1) HIGH! ======== Nov 12 18:02:36 ivanpaul kernel: [ 691.910678] [WLAN_RFKILL]: rockchip_wifi_power: 1 Nov 12 18:02:36 ivanpaul kernel: [ 691.910686] [WLAN_RFKILL]: wifi turn on power. -1 Nov 12 18:02:36 ivanpaul nm-dispatcher: req:4 'down' [wlan0]: start running ordered scripts... Nov 12 18:02:36 ivanpaul kernel: [ 692.010930] usb 3-1: new low-speed USB device number 3 using ohci-platform Nov 12 18:02:36 ivanpaul wpa_supplicant[503]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Nov 12 18:02:36 ivanpaul kernel: [ 692.123110] usb 1-1.2: New USB device found, idVendor=0c45, idProduct=6321 Nov 12 18:02:36 ivanpaul kernel: [ 692.123123] usb 1-1.2: New USB device strings: Mfr=2, Product=1, SerialNumber=0 Nov 12 18:02:36 ivanpaul kernel: [ 692.123130] usb 1-1.2: Product: USB Camera Nov 12 18:02:36 ivanpaul kernel: [ 692.123137] usb 1-1.2: Manufacturer: Sonix Technology Co., Ltd. Nov 12 18:02:36 ivanpaul kernel: [ 692.126450] uvcvideo: Found UVC 1.00 device USB Camera (0c45:6321) Nov 12 18:02:36 ivanpaul systemd-udevd[2540]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/fe3c0000.usb/usb1/1-1/1-1.2 1 4': No such file or directory Nov 12 18:02:36 ivanpaul kernel: [ 692.211462] sdio_reset_comm(): Nov 12 18:02:36 ivanpaul kernel: [ 692.237626] mmc_host mmc2: Bus speed (slot 0) = 400000Hz (slot req 400000Hz, actual 400000HZ div = 0) Nov 12 18:02:36 ivanpaul kernel: [ 692.255627] mmc_host mmc2: Bus speed (slot 0) = 100000Hz (slot req 100000Hz, actual 100000HZ div = 0) Nov 12 18:02:36 ivanpaul kernel: [ 692.309787] usb 3-1: New USB device found, idVendor=258a, idProduct=001e Nov 12 18:02:36 ivanpaul kernel: [ 692.309808] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Nov 12 18:02:36 ivanpaul kernel: [ 692.309820] usb 3-1: Product: USB KEYBOARD Nov 12 18:02:36 ivanpaul kernel: [ 692.309831] usb 3-1: Manufacturer: HAILUCK CO.,LTD Nov 12 18:02:36 ivanpaul kernel: [ 692.318007] mmc2: queuing unknown CIS tuple 0x80 (2 bytes) Nov 12 18:02:36 ivanpaul kernel: [ 692.320689] input: HAILUCK CO.,LTD USB KEYBOARD as /devices/platform/fe3a0000.usb/usb3/3-1/3-1:1.0/0003:258A:001E.0003/input/input4 Nov 12 18:02:36 ivanpaul kernel: [ 692.324330] mmc2: queuing unknown CIS tuple 0x80 (3 bytes) Nov 12 18:02:36 ivanpaul kernel: [ 692.330827] mmc2: queuing unknown CIS tuple 0x80 (3 bytes) Nov 12 18:02:36 ivanpaul kernel: [ 692.341877] mmc2: queuing unknown CIS tuple 0x80 (7 bytes) Nov 12 18:02:36 ivanpaul kernel: [ 692.355357] mmc2: queuing unknown CIS tuple 0x81 (9 bytes) Nov 12 18:02:36 ivanpaul kernel: [ 692.375233] hid-generic 0003:258A:001E.0003: input,hidraw0: USB HID v1.10 Keyboard [HAILUCK CO.,LTD USB KEYBOARD] on usb-fe3a0000.usb-1/input0 Nov 12 18:02:36 ivanpaul kernel: [ 692.419602] input: HAILUCK CO.,LTD USB KEYBOARD Touchpad as /devices/platform/fe3a0000.usb/usb3/3-1/3-1:1.1/0003:258A:001E.0004/input/input5 Nov 12 18:02:36 ivanpaul kernel: [ 692.472980] hid-multitouch 0003:258A:001E.0004: input,hiddev0,hidraw1: USB HID v1.10 Mouse [HAILUCK CO.,LTD USB KEYBOARD] on usb-fe3a0000.usb-1/input1 Nov 12 18:02:36 ivanpaul systemd-udevd[2550]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/fe3a0000.usb/usb3/3-1 3 3': No such file or directory Nov 12 18:02:37 ivanpaul systemd-udevd[2548]: Error calling EVIOCSKEYCODE on device node '/dev/input/event2' (scan code 0x700a5, key code 224): Invalid argument Nov 12 18:02:37 ivanpaul systemd-udevd[2548]: Error calling EVIOCSKEYCODE on device node '/dev/input/event2' (scan code 0x700a6, key code 225): Invalid argument Nov 12 18:02:37 ivanpaul kernel: [ 692.573345] mmc_host mmc2: Bus speed (slot 0) = 84500000Hz (slot req 90000000Hz, actual 84500000HZ div = 0) Nov 12 18:02:37 ivanpaul kernel: [ 692.594807] dwmmc_rockchip fe310000.dwmmc: All phases work, using default phase 0. Nov 12 18:02:37 ivanpaul kernel: [ 692.594871] sdioh_start: set sd_f2_blocksize 256 Nov 12 18:02:37 ivanpaul kernel: [ 692.595263] Nov 12 18:02:37 ivanpaul kernel: [ 692.595263] Nov 12 18:02:37 ivanpaul kernel: [ 692.595263] dhd_bus_devreset: == WLAN ON == Nov 12 18:02:37 ivanpaul kernel: [ 692.596309] F1 signature read @0x18000000=0x15294345 Nov 12 18:02:37 ivanpaul kernel: [ 692.602095] F1 signature OK, socitype:0x1 chip:0x4345 rev:0x9 pkg:0x2 Nov 12 18:02:37 ivanpaul kernel: [ 692.603201] DHD: dongle ram size is set to 819200(orig 819200) at 0x198000 Nov 12 18:02:37 ivanpaul kernel: [ 692.603277] dhd_bus_set_default_min_res_mask: Unhandled chip id Nov 12 18:02:37 ivanpaul kernel: [ 692.603818] dhd_conf_read_config: Ignore config file /lib/firmware/brcm/config.txt Nov 12 18:02:37 ivanpaul kernel: [ 692.603833] Final fw_path=/lib/firmware/brcm/fw_bcm43456c5_ag.bin Nov 12 18:02:37 ivanpaul kernel: [ 692.603837] Final nv_path=/lib/firmware/brcm/nvram_ap6256.txt Nov 12 18:02:37 ivanpaul kernel: [ 692.603841] Final clm_path=/lib/firmware/brcm/clm.blob Nov 12 18:02:37 ivanpaul kernel: [ 692.603844] Final conf_path=/lib/firmware/brcm/config.txt Nov 12 18:02:37 ivanpaul kernel: [ 692.604428] dhd_os_open_image: /lib/firmware/brcm/fw_bcm43456c5_ag.bin (482927 bytes) open success Nov 12 18:02:37 ivanpaul kernel: [ 692.653492] dhd_os_open_image: /lib/firmware/brcm/nvram_ap6256.txt (2196 bytes) open success Nov 12 18:02:37 ivanpaul kernel: [ 692.653522] NVRAM version: AP6256_NVRAM_V1.1_08252017 Nov 12 18:02:37 ivanpaul kernel: [ 692.653892] dhdsdio_write_vars: Download, Upload and compare of NVRAM succeeded. Nov 12 18:02:37 ivanpaul kernel: [ 692.729213] dhd_bus_init: enable 0x06, ready 0x06 (waited 0us) Nov 12 18:02:37 ivanpaul kernel: [ 692.729703] dhd_get_memdump_info: File [/data/misc/wifi/.memdump.info] doesn't exist Nov 12 18:02:37 ivanpaul kernel: [ 692.729710] dhd_get_memdump_info: MEMDUMP ENABLED = 2 Nov 12 18:02:37 ivanpaul kernel: [ 692.734815] dhd_tcpack_suppress_set: TCP ACK Suppress mode 0 -> mode 1 Nov 12 18:02:37 ivanpaul kernel: [ 692.735373] dhd_apply_default_clm: Ignore clm file /lib/firmware/brcm/clm.blob Nov 12 18:02:37 ivanpaul kernel: [ 692.737820] Firmware up: op_mode=0x0005, MAC=6c:21:a2:e8:2e:d3 Nov 12 18:02:37 ivanpaul kernel: [ 692.759070] Driver: 1.579.77.41.10 (r) Nov 12 18:02:37 ivanpaul kernel: [ 692.759070] Firmware: wl0: Jun 16 2017 12:38:26 version 7.45.96.2 (66c4e21@sh-git) (r) FWID 01-1813af84 Nov 12 18:02:37 ivanpaul kernel: [ 692.759070] CLM: 9.2.9 Nov 12 18:02:37 ivanpaul kernel: [ 692.760444] dhd_txglom_enable: enable 1 Nov 12 18:02:37 ivanpaul kernel: [ 692.760453] dhd_conf_set_txglom_params: txglom_mode=copy Nov 12 18:02:37 ivanpaul kernel: [ 692.760458] dhd_conf_set_txglom_params: txglomsize=36, deferred_tx_len=0 Nov 12 18:02:37 ivanpaul kernel: [ 692.760463] dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Nov 12 18:02:37 ivanpaul kernel: [ 692.760468] dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=-1 Nov 12 18:02:37 ivanpaul kernel: [ 692.760479] dhd_conf_get_disable_proptx: fw_proptx=1, disable_proptx=-1 Nov 12 18:02:37 ivanpaul kernel: [ 692.762551] dhd_wlfc_hostreorder_init(): successful bdcv2 tlv signaling, 64 Nov 12 18:02:37 ivanpaul kernel: [ 692.764552] dhd_pno_init: Support Android Location Service Nov 12 18:02:37 ivanpaul kernel: [ 692.784529] CFG80211-ERROR) wl_cfg80211_event : Event handler is not created Nov 12 18:02:37 ivanpaul kernel: [ 692.785188] rtt_do_get_ioctl: failed to send getbuf proxd iovar (CMD ID : 1), status=-23 Nov 12 18:02:37 ivanpaul kernel: [ 692.785282] dhd_rtt_init : FTM is not supported Nov 12 18:02:37 ivanpaul kernel: [ 692.785290] dhd_preinit_ioctls: SensorHub diabled 0 Nov 12 18:02:37 ivanpaul kernel: [ 692.785865] dhd_preinit_ioctls failed to set ShubHub disable Nov 12 18:02:37 ivanpaul kernel: [ 692.788266] dhd_conf_set_country: set country CN, revision 38 Nov 12 18:02:37 ivanpaul kernel: [ 692.788273] CFG80211-ERROR) wl_cfg80211_event : Event handler is not created Nov 12 18:02:37 ivanpaul kernel: [ 692.790945] Country code: CN (CN/38) Nov 12 18:02:37 ivanpaul kernel: [ 692.793314] CONFIG-ERROR) dhd_conf_set_intiovar: txbf setting failed -23 Nov 12 18:02:37 ivanpaul kernel: [ 692.793609] wl_android_wifi_on: Success Nov 12 18:02:37 ivanpaul kernel: [ 692.819300] dhd_open : the lock is released. Nov 12 18:02:37 ivanpaul kernel: [ 692.819316] dhd_open: Exit ret=0 Nov 12 18:02:37 ivanpaul dhcpcd[439]: wlan0: carrier acquired Nov 12 18:02:37 ivanpaul dhcpcd[439]: wlan0: adding address fe80::d867:58fc:d1c4:e23d Nov 12 18:02:37 ivanpaul dhcpcd[439]: wlan0: IAID a2:e8:2e:d3 Nov 12 18:02:37 ivanpaul dhcpcd[439]: wlan0: carrier lost Nov 12 18:02:37 ivanpaul kernel: [ 692.901030] P2P interface registered Nov 12 18:02:37 ivanpaul kernel: [ 692.901044] wl_cfgp2p_add_p2p_disc_if: wdev: ffffffc0d0369800, wdev->net: (null) Nov 12 18:02:37 ivanpaul dhcpcd[439]: wlan0: deleting address fe80::d867:58fc:d1c4:e23d Nov 12 18:02:37 ivanpaul kernel: [ 692.922212] WLC_E_IF: NO_IF set, event Ignored Nov 12 18:02:37 ivanpaul kernel: [ 692.923416] P2P interface started Nov 12 18:02:37 ivanpaul NetworkManager[377]: [1573581757.4213] sup-iface[0xab02a260,wlan0]: supports 5 scan SSIDs Nov 12 18:02:37 ivanpaul NetworkManager[377]: [1573581757.4291] device (wlan0): supplicant interface state: starting -> ready Nov 12 18:02:37 ivanpaul NetworkManager[377]: [1573581757.4294] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Nov 12 18:02:37 ivanpaul kernel: [ 692.962512] wl_run_escan: LEGACY_SCAN sync ID: 9, bssidx: 0 Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.7848] device (wlan0): supplicant interface state: ready -> inactive Nov 12 18:02:39 ivanpaul kernel: [ 695.319574] wl_run_escan: LEGACY_SCAN sync ID: 10, bssidx: 0 Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.8931] policy: auto-activating connection 'EasyBox-095483 2' Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.8973] device (wlan0): Activation: starting connection 'EasyBox-095483 2' (cac06e09-5fe1-41aa-9aea-968b0246d874) Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.8993] device (wlan0): state change: disconnected -> prepare (reason 'none') [30 40 0] Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9011] manager: NetworkManager state is now CONNECTING Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9053] device (wlan0): state change: prepare -> config (reason 'none') [40 50 0] Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9078] device (wlan0): Activation: (wifi) access point 'EasyBox-095483 2' has security, but secrets are required. Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9090] device (wlan0): state change: config -> need-auth (reason 'none') [50 60 0] Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9278] device (wlan0): state change: need-auth -> prepare (reason 'none') [60 40 0] Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9403] device (wlan0): state change: prepare -> config (reason 'none') [40 50 0] Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9420] device (wlan0): Activation: (wifi) connection 'EasyBox-095483 2' has security, and secrets exist. No new secrets needed. Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9434] Config: added 'ssid' value 'EasyBox-095483' Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9485] Config: added 'scan_ssid' value '1' Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9497] Config: added 'key_mgmt' value 'WPA-PSK' Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9507] Config: added 'auth_alg' value 'OPEN' Nov 12 18:02:39 ivanpaul NetworkManager[377]: [1573581759.9508] Config: added 'psk' value '' Nov 12 18:02:42 ivanpaul wpa_supplicant[503]: wlan0: Trying to associate with 94:4a:0c:e5:65:fc (SSID='EasyBox-095483' freq=2437 MHz) Nov 12 18:02:42 ivanpaul kernel: [ 697.660438] Connecting with 94:4a:0c:e5:65:fc ssid "EasyBox-095483", len (14) channel=6 Nov 12 18:02:42 ivanpaul kernel: [ 697.660438] Nov 12 18:02:42 ivanpaul kernel: [ 697.665749] dhd_dbg_start_pkt_monitor, 1724 Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.1568] device (wlan0): supplicant interface state: inactive -> associating Nov 12 18:02:42 ivanpaul kernel: [ 697.719212] wl_iw_event: Link UP with 94:4a:0c:e5:65:fc Nov 12 18:02:42 ivanpaul kernel: [ 697.719298] wl_bss_connect_done succeeded with 94:4a:0c:e5:65:fc Nov 12 18:02:42 ivanpaul wpa_supplicant[503]: wlan0: Associated with 94:4a:0c:e5:65:fc Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.2173] device (wlan0): supplicant interface state: associating -> associated Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.2627] device (wlan0): supplicant interface state: associated -> 4-way handshake Nov 12 18:02:42 ivanpaul kernel: [ 697.787918] wl_bss_connect_done succeeded with 94:4a:0c:e5:65:fc vndr_oui: 00-10-18 Nov 12 18:02:42 ivanpaul wpa_supplicant[503]: wlan0: WPA: Key negotiation completed with 94:4a:0c:e5:65:fc [PTK=CCMP GTK=TKIP] Nov 12 18:02:42 ivanpaul wpa_supplicant[503]: wlan0: CTRL-EVENT-CONNECTED - Connection to 94:4a:0c:e5:65:fc completed [id=0 id_str=] Nov 12 18:02:42 ivanpaul dhcpcd[439]: wlan0: carrier acquired Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.5763] device (wlan0): supplicant interface state: 4-way handshake -> completed Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.5765] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'EasyBox-095483'. Nov 12 18:02:42 ivanpaul dhcpcd[439]: wlan0: adding address fe80::d3cf:71c4:1f6d:d162 Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.5769] device (wlan0): state change: config -> ip-config (reason 'none') [50 70 0] Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.5787] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds) Nov 12 18:02:42 ivanpaul dhcpcd[439]: wlan0: IAID a2:e8:2e:d3 Nov 12 18:02:42 ivanpaul NetworkManager[377]: [1573581762.5958] dhcp4 (wlan0): dhclient started with pid 2622 Nov 12 18:02:42 ivanpaul dhclient[2622]: DHCPREQUEST of 192.168.2.189 on wlan0 to 255.255.255.255 port 67 Nov 12 18:02:42 ivanpaul dhcpcd[439]: wlan0: rebinding lease of 192.168.2.189 Nov 12 18:02:43 ivanpaul dhcpcd[439]: wlan0: soliciting an IPv6 router Nov 12 18:02:43 ivanpaul ntpd[533]: bind(23) AF_INET6 fe80::c047:60a:2557:1879%2#123 flags 0x11 failed: Cannot assign requested address Nov 12 18:02:43 ivanpaul ntpd[533]: unable to create socket on wlan0 (8) for fe80::c047:60a:2557:1879%2#123 Nov 12 18:02:43 ivanpaul ntpd[533]: failed to init interface for address fe80::c047:60a:2557:1879%2 Nov 12 18:02:44 ivanpaul kernel: [ 699.532453] Error getting the SSID Nov 12 18:02:44 ivanpaul avahi-daemon[342]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::c047:60a:2557:1879. Nov 12 18:02:44 ivanpaul avahi-daemon[342]: New relevant interface wlan0.IPv6 for mDNS. Nov 12 18:02:44 ivanpaul avahi-daemon[342]: Registering new address record for fe80::c047:60a:2557:1879 on wlan0.*. Nov 12 18:02:44 ivanpaul dhcpcd[439]: wlan0: Router Advertisement from fe80::964a:cff:fee5:65f8 Nov 12 18:02:44 ivanpaul dhcpcd[439]: wlan0: ignoring RA from fe80::964a:cff:fee5:65f8 (no public prefix, no managed address) Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.1249] dhcp6 (wlan0): activation: beginning transaction (timeout in 45 seconds) Nov 12 18:02:44 ivanpaul dhcpcd[439]: wlan0: requesting DHCPv6 information Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.1252] dhcp6 (wlan0): hostname is not a FQDN, it will be ignored Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.1324] dhcp6 (wlan0): dhclient started with pid 2657 Nov 12 18:02:44 ivanpaul dhclient[2657]: RCV: Reply message on wlan0 from fe80::964a:cff:fee5:65f8. Nov 12 18:02:44 ivanpaul dhclient[2657]: Packet received, but nothing done with it. Nov 12 18:02:44 ivanpaul dhclient[2657]: XMT: Info-Request on wlan0, interval 910ms. Nov 12 18:02:44 ivanpaul dhclient[2657]: RCV: Reply message on wlan0 from fe80::964a:cff:fee5:65f8. Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.7632] dhcp6 (wlan0): nameserver 'fd91:dab6:a2b2:1:964a:cff:fee5:65f8' Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.7633] dhcp (wlan0): domain search 'local.' Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.7634] dhcp6 (wlan0): state changed unknown -> bound Nov 12 18:02:44 ivanpaul nm-dispatcher: req:5 'dhcp6-change' [wlan0]: new request (2 scripts) Nov 12 18:02:44 ivanpaul nm-dispatcher: req:5 'dhcp6-change' [wlan0]: start running ordered scripts... Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.7910] dhcp6 (wlan0): client pid 2657 exited with status 0 Nov 12 18:02:44 ivanpaul NetworkManager[377]: [1573581764.7913] dhcp6 (wlan0): state changed bound -> done Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.2635] device (wlan0): state change: ip-config -> ip-check (reason 'none') [70 80 0] Nov 12 18:02:45 ivanpaul avahi-daemon[342]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::c047:60a:2557:1879. Nov 12 18:02:45 ivanpaul avahi-daemon[342]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee. Nov 12 18:02:45 ivanpaul avahi-daemon[342]: Registering new address record for fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee on wlan0.*. Nov 12 18:02:45 ivanpaul avahi-daemon[342]: Withdrawing address record for fe80::c047:60a:2557:1879 on wlan0. Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.2739] device (wlan0): state change: ip-check -> secondaries (reason 'none') [80 90 0] Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.2780] device (wlan0): state change: secondaries -> activated (reason 'none') [90 100 0] Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.2792] manager: NetworkManager state is now CONNECTED_LOCAL Nov 12 18:02:45 ivanpaul nm-dispatcher: req:6 'connectivity-change': new request (2 scripts) Nov 12 18:02:45 ivanpaul nm-dispatcher: req:6 'connectivity-change': start running ordered scripts... Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.2996] manager: NetworkManager state is now CONNECTED_GLOBAL Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.3000] policy: set 'EasyBox-095483 2' (wlan0) as default for IPv6 routing and DNS Nov 12 18:02:45 ivanpaul NetworkManager[377]: [1573581765.3017] device (wlan0): Activation: successful, device activated. Nov 12 18:02:45 ivanpaul nm-dispatcher: req:7 'up' [wlan0]: new request (2 scripts) Nov 12 18:02:45 ivanpaul nm-dispatcher: req:7 'up' [wlan0]: start running ordered scripts... Nov 12 18:02:45 ivanpaul systemd[1]: Reloading OpenBSD Secure Shell server. Nov 12 18:02:45 ivanpaul systemd[1]: Reloaded OpenBSD Secure Shell server. Nov 12 18:02:45 ivanpaul dhcpcd[439]: wlan0: applying ignored RA from fe80::964a:cff:fee5:65f8 Nov 12 18:02:45 ivanpaul dhcpcd[439]: wlan0: adding route to fd91:dab6:a2b2:1::/64 Nov 12 18:02:45 ivanpaul dhcpcd[439]: wlan0: adding default route via fe80::964a:cff:fee5:65f8 Nov 12 18:02:45 ivanpaul dhcpcd[439]: wlan0: removing route to fd91:dab6:a2b2:1::/64 Nov 12 18:02:45 ivanpaul dhcpcd[439]: wlan0: removing default route via fe80::964a:cff:fee5:65f8 Nov 12 18:02:46 ivanpaul dhclient[2622]: DHCPREQUEST of 192.168.2.189 on wlan0 to 255.255.255.255 port 67 Nov 12 18:02:46 ivanpaul dhclient[2622]: DHCPACK of 192.168.2.189 from 192.168.2.1 Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5029] dhcp4 (wlan0): address 192.168.2.189 Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5030] dhcp4 (wlan0): plen 24 (255.255.255.0) Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5031] dhcp4 (wlan0): gateway 192.168.2.1 Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5032] dhcp4 (wlan0): server identifier 192.168.2.1 Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5032] dhcp4 (wlan0): lease time 31536000 Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5033] dhcp4 (wlan0): hostname 'ivanpaul' Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5033] dhcp4 (wlan0): nameserver '192.168.2.1' Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5034] dhcp4 (wlan0): domain name 'local' Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5034] dhcp4 (wlan0): state changed unknown -> bound Nov 12 18:02:46 ivanpaul avahi-daemon[342]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.189. Nov 12 18:02:46 ivanpaul avahi-daemon[342]: New relevant interface wlan0.IPv4 for mDNS. Nov 12 18:02:46 ivanpaul avahi-daemon[342]: Registering new address record for 192.168.2.189 on wlan0.IPv4. Nov 12 18:02:46 ivanpaul dhclient[2622]: bound to 192.168.2.189 -- renewal in 12975379 seconds. Nov 12 18:02:46 ivanpaul NetworkManager[377]: [1573581766.5206] policy: set 'EasyBox-095483 2' (wlan0) as default for IPv4 routing and DNS Nov 12 18:02:46 ivanpaul nm-dispatcher: req:8 'dhcp4-change' [wlan0]: new request (2 scripts) Nov 12 18:02:46 ivanpaul nm-dispatcher: req:8 'dhcp4-change' [wlan0]: start running ordered scripts... Nov 12 18:02:47 ivanpaul dhcpcd[439]: wlan0: probing address 192.168.2.189/24 Nov 12 18:02:47 ivanpaul ntpd[533]: Listen normally on 9 wlan0 192.168.2.189:123 Nov 12 18:02:47 ivanpaul ntpd[533]: Listen normally on 10 wlan0 [fd91:dab6:a2b2:1:78b6:5ed3:c08c:ceee]:123 Nov 12 18:02:47 ivanpaul ntpd[533]: Listen normally on 11 wlan0 [fe80::c047:60a:2557:1879%2]:123 Nov 12 18:02:48 ivanpaul kernel: [ 704.050637] Error getting the SSID Nov 12 18:02:48 ivanpaul kernel: [ 704.053074] Error getting the SSID Nov 12 18:02:52 ivanpaul dhcpcd[439]: wlan0: leased 192.168.2.189 for 31536000 seconds Nov 12 18:02:52 ivanpaul dhcpcd[439]: wlan0: adding route to 192.168.2.0/24 Nov 12 18:02:52 ivanpaul dhcpcd[439]: wlan0: adding default route via 192.168.2.1 Nov 12 18:02:52 ivanpaul dhcpcd[439]: wlan0: removing route to 192.168.2.0/24 Nov 12 18:02:52 ivanpaul dhcpcd[439]: wlan0: removing default route via 192.168.2.1 Nov 12 18:02:54 ivanpaul kernel: [ 709.772730] Error getting the SSID Nov 12 18:02:54 ivanpaul kernel: [ 709.777104] Error getting the SSID Nov 12 18:03:02 ivanpaul kernel: [ 718.116732] wl_run_escan: LEGACY_SCAN sync ID: 11, bssidx: 0 Nov 12 18:03:24 ivanpaul ntpd[533]: Soliciting pool server 144.76.96.7 Nov 12 18:03:45 ivanpaul kernel: [ 761.136447] wl_run_escan: LEGACY_SCAN sync ID: 12, bssidx: 0