Bug 194931

Summary:	iwlwifi: 7260: data gets stuck after a while with Android Nougat (7.0, 7.1) as a SoftAP
Product:	Drivers	Reporter:	Jason Vas Dias (jason.vas.dias)
Component:	network-wireless	Assignee:	DO NOT USE - assign "network-wireless-intel" component instead (linuxwifi)
Status:	CLOSED INVALID
Severity:	high	CC:	linuxwifi, luca
Priority:	P1
Hardware:	All
OS:	Linux
Kernel Version:	4.10.0	Subsystem:
Regression:	Yes	Bisected commit-id:
Attachments:	/etc/hostapd/hostapd_default.conf from my un-rooted Android 7.0 device 'adb logcat' from USB connected AP, from @8mins before disconnect, showing disconnect & reconnect

Description Jason Vas Dias 2017-03-19 12:32:01 UTC

This is stackexchange issue :
http://android.stackexchange.com/questions/171241/wifi-hotspot-timeout-setting-gone-in-nougat-7-0-7-1-but-timeout-has-not

I think the restructured iwlwifi driver in Linux 4.10
(which updated the firmware of my wireless networking device:

Class:	Network controller
Vendor:	Intel Corporation
Device:	Wireless 7260
SVendor:	Intel Corporation
SDevice:	Dual Band Wireless-AC 7260
Rev:	bb
Driver:	iwlwifi

) 
is having problems handling the new Android 7.0+ hostapd's
sending of empty data frames on inactivity timeout .

I have connected my Linux 4.10 x86_64 laptop via iwlwifi wireless
connection to an Access Point provided by Android 7.0's hostapd .

This setup used to work flawlessly with my old Android 4.2.2 phone,
with same Linux 4.10 iwlwifi code .

But my old phone's microphone died, and its USB connection was gone, 
so I had to invest in a new 4G Android 7.0 phone ( there is still
a €9 flash sale on for these devices at agmmobile&dot;com, since
the latest model of the AGM A8 comes with QualComm 425 chipset, 
whereas the €9 units, like mine, are the older QualComm 410 MSM8916 chipset). 
But nevertheless a great, robust phone with very long battery life &
superfast 4G GSM internet.

Now in Android (7.0, 7.1) there are no Wifi-HotSpot/Tethering Timeout settings 
settable by non-root users.

Android 7.0's /etc/hostapd/hostapd_default.conf says:

    # Station inactivity limit
    #
    # If a station does not send anything in ap_max_inactivity seconds, an
    # empty data frame is sent to it in order to verify whether it is
    # still in range. If this frame is not ACKed, the station will be
    # disassociated and then deauthenticated. This feature is used to
    # clear station table of old entries when the STAs move out of the
    # range.
    #
    # The station can associate again with the AP if it is still in range;
    # this inactivity poll is just used as a nicer way of verifying
    # inactivity; i.e., client will not report broken connection because
    # disassociation frame is not sent immediately without first polling
    # the STA with a data frame.
    # default: 300 (i.e., 5 minutes)
    #ap_max_inactivity=300

On Android 4.2.2, I had the inactivity timeout set to 60 minutes, and
no timeouts ever occurred.

I think what is happening is that this default value is taking effect ,
and the iwlwifi driver is not liking this empty data frame sent by Android
7.0's hostapd - as soon as it receives one of these frames, the link goes
down and all further transmission on it is impossible, but wpa_supplicant
and dhclient still think all is OK ( the timeout is much less than the 
DHCP lease time given out by Android's dnsmasqd ).

I had to write a 'wlan_ping_monitor.sh' script to keep the link alive 
(attached to the stackexhange report) , which periodically pings a 
public internet host ; this has the effect of reducing the dead link
problem from once every 2-5 minutes to @ once per hour, but it still
occurs - I see messages in the log like:

Mar 19 10:52:42 jvdlux ntpd[5696]: Deleting interface #3 wlp6s0, 192.168.43.124#123, interface stats: received=189, sent=191, dropped=0, active_time=3589 secs
Mar 19 10:52:42 jvdlux ntpd[5696]: 54.171.104.100 local addr 192.168.43.124 -> <null>
Mar 19 10:52:42 jvdlux ntpd[5696]: 89.234.64.77 local addr 192.168.43.124 -> <null>
Mar 19 10:52:42 jvdlux ntpd[5696]: 193.1.219.116 local addr 192.168.43.124 -> <null>
Mar 19 10:52:42 jvdlux ntpd[5696]: 193.1.12.167 local addr 192.168.43.124 -> <null>

ie. NO messages from iwlwifi or wpa_supplicant - only ntpd notices that link
is down. I think if it has to bring the link down, iwlwifi should be 
emitting something to the log.

So my ping monitor script fails its pings and stops & restarts the network:

Mar 19 10:52:43 jvdlux root: wlan_ping_monitor: ping 192.168.43.1 or 147.75.205.195 failed.
Mar 19 10:52:45 jvdlux last message repeated 2 times
Mar 19 10:52:46 jvdlux root: wlan_ping_monitor: interface  is down. Could not ping 192.168.43.1 or 147.75.205.195. Restarting Network...
Mar 19 10:52:46 jvdlux dhclient: Killed old client process
Mar 19 10:52:47 jvdlux dhclient: Internet Systems Consortium DHCP Client 4.3.4
Mar 19 10:52:47 jvdlux dhclient: Copyright 2004-2016 Internet Systems Consortium.
Mar 19 10:52:47 jvdlux dhclient: All rights reserved.
Mar 19 10:52:47 jvdlux dhclient: For info, please visit https://www.isc.org/software/dhcp/
Mar 19 10:52:47 jvdlux dhclient: 
Mar 19 10:52:47 jvdlux dhclient: Listening on Socket/wlp6s0
Mar 19 10:52:47 jvdlux dhclient: Sending on   Socket/wlp6s0
Mar 19 10:52:47 jvdlux dhclient: DHCPRELEASE on wlp6s0 to 192.168.43.1 port 67
...
Mar 19 10:53:08 jvdlux dhclient: Internet Systems Consortium DHCP Client 4.3.4
Mar 19 10:53:08 jvdlux dhclient: Copyright 2004-2016 Internet Systems Consortium.
Mar 19 10:53:08 jvdlux dhclient: All rights reserved.
Mar 19 10:53:08 jvdlux dhclient: For info, please visit https://www.isc.org/software/dhcp/
Mar 19 10:53:08 jvdlux dhclient: 
Mar 19 10:53:08 jvdlux root: dhclient-script: DHCP Client set environment: interface=wlp6s0 reason=PREINIT PATH=/usr/sbin:/sbin:/bin:/usr/sbin:/usr/bin pid=7846 PWD=/ SHLVL=1 _=/bin/env
Mar 19 10:53:08 jvdlux dhclient: Listening on Socket/wlp6s0
Mar 19 10:53:08 jvdlux dhclient: Sending on   Socket/wlp6s0
Mar 19 10:53:08 jvdlux dhclient: DHCPDISCOVER on wlp6s0 to 255.255.255.255 port 67 interval 3
Mar 19 10:53:09 jvdlux dhclient: DHCPREQUEST on wlp6s0 to 255.255.255.255 port 67
Mar 19 10:53:09 jvdlux dhclient: DHCPOFFER from 192.168.43.1
Mar 19 10:53:09 jvdlux dhclient: DHCPACK from 192.168.43.1
Mar 19 10:53:09 jvdlux root: dhclient-script: DHCP Client set environment: old_subnet_mask=255.255.255.0 requested_host_name=1 new_vendor_encapsulated_options=ANDROID_METERED old_domain_name_servers=127.0.0.1 old_broadcast_address=192.168.43.255 old_expiry=1489920767 new_host_name=jvdlux new_subnet_mask=255.255.255.0 requested_time_offset=1 new_next_server=192.168.43.1 new_ip_address=192.168.43.124 new_network_number=192.168.43.0 interface=wlp6s0 reason=BOUND old_dhcp_rebinding_time=3150 old_dhcp_message_type=5 new_expiry=1489924389 PATH=/usr/sbin:/sbin:/bin:/usr/sbin:/usr/bin new_dhcp_lease_time=3600 pid=7846 new_dhcp_server_identifier=192.168.43.1 PWD=/ old_host_name=jvdlux new_dhcp_renewal_time=1800 requested_subnet_mask=1 new_routers=192.168.43.1 requested_domain_name=1 new_domain_name_servers=127.0.0.1 SHLVL=1 requested_domain_name_servers=1 old_dhcp_server_identifier=192.168.43.1 new_dhcp_message_type=5 old_ip_address=192.168.43.124 old_vendor_encapsulated_options=ANDROID_METERED old_dhcp_renewal_time=1
Mar 19 10:53:10 jvdlux ntpd[5696]: Listen normally on 6 wlp6s0 [fe80::fa16:54ff:fef7:d66d%3]:123
Mar 19 10:53:10 jvdlux ntpd[5696]: new interface(s) found: waking up resolver
Mar 19 10:53:11 jvdlux root: dhclient-script: Configuring new IPv4 address : 192.168.43.124/24 255.255.255.0 brd: 192.168.43.255 lifetime: 3600
Mar 19 10:53:11 jvdlux dhclient: bound to 192.168.43.124 -- renewal in 1539 seconds.
Mar 19 10:53:13 jvdlux ntpd[5696]: Listen normally on 7 wlp6s0 192.168.43.124:123
Mar 19 10:53:13 jvdlux ntpd[5696]: new interface(s) found: waking up resolver
Mar 19 10:53:14 jvdlux root: wlan_ping_monitor : started.

Please can iwlwifi developers try connecting through an unrooted
Android 7.0+ device hostapd - they will see the link goes dead after 
2-5 mins of inactivity, and no way to stop Android doing this.

Comment 1 Jason Vas Dias 2017-03-19 13:19:28 UTC

Probably also wpa_supplicant needs to be updated to use same dead link detection
as ntpd - I will check if this is feasible -  that might be a simpler workaround. But it would help if iwlwifi did not drop the link in the first place & ACK-ed the empty data frame sent by Android 7.0's hostapd.

Comment 2 Jason Vas Dias 2017-03-19 13:59:51 UTC

Wireless tools versions used:
  iw version 4.9 
  iproute2 version iproute2-ss161212
  wpa_supplicant version 2.7-devel
  ISC dhclient 4.3.4 (needs upgrade)
all with Linux 4.10.0 (built from linux-stable GIT).

Comment 3 Jason Vas Dias 2017-03-20 13:27:58 UTC

The plot thickens. This bug cannot be entirely inactivity related .
Even with the ping monitor pinging a WAN host every 8 seconds, AND
the linux 4.10 AP client host playing a live audio stream , the interface
unaccountably goes dead every hour or so - it appears to be some periodic
timeout, but it cannot be inactivity, since active transmissions were ongoing
when the link went down.

There does appear to be some hourly timeout going on. It happened 3 times today,
at almost exactly 1 hour intervals, and each time the interface was ACTIVE -
pinging and live audio stream playback were ongoing:

Mar 20 11:09:01 jvdlux root: wlan_ping_monitor: interface is down. Could not ping 192.168.43.1 or 147.75.205.195. Restarting Network...
Mar 20 12:09:36 jvdlux root: wlan_ping_monitor: interface is down. Could not ping 192.168.43.1 or 147.75.205.195. Restarting Network...
Mar 20 13:10:13 jvdlux root: wlan_ping_monitor: interface is down. Could not ping 192.168.43.1 or 147.75.205.195. Restarting Network...

So 'ping -n -q -c 2 -W 8 147.75.205.195' timed out (one of the few public internet hosts still responding to ICMP - thank you!) , AND
'ping -n -q -c 1 -W 4 192.168.43.1' (my Android 7.0 AP) timed out, and
only ntpd (not wpa_supplicant!) notices the link goes down:

Mar 20 13:10:05 jvdlux ntpd[31393]: Deleting interface #9 wlp6s0, 192.168.43.124#123, interface stats: received=58, sent=59, dropped=0, active_time=3602 secs
Mar 20 13:10:05 jvdlux ntpd[31393]: 86.43.77.42 local addr 192.168.43.124 -> <null>
Mar 20 13:10:05 jvdlux ntpd[31393]: 193.1.31.66 local addr 192.168.43.124 -> <null>
Mar 20 13:10:05 jvdlux ntpd[31393]: 52.17.30.119 local addr 192.168.43.124 -> <null>
Mar 20 13:10:05 jvdlux ntpd[31393]: 54.194.18.100 local addr 192.168.43.124 -> <null>

No messages at all are seen from the kernel when this happens. This in itself
is a major bug. Nothing in the kernel should be deciding to bring down an interface without complaining loudly about it to the log.

I'm increasing severity of this bug, because it appears linux-4.10 is unable
to maintain reliable communications via an Android 7.0 wireless hotspot at all
for more than one hour, regardless of activity / inactivity on the link.
It is also a regression because no such problems are observed when connecting
to an Android 4.2.2 wireless hotspot AP.

Comment 4 Jason Vas Dias 2017-03-21 19:48:17 UTC

I'd greatly appreciate some advice from Intel WiFi developers about this .
What actions does the iwlwifi driver take on receipt of an empty data frame such
as those sent by Android 7.0 hostapd on inactivity (5mins) or hourly maximum connect time timeout ?
What would be involved in changing it to ACK such frames ?
Otherwise I will have to hack up a version of iwlwifi that ACKs empty data 
frames so that I can use, develop & test internet service applications that
require long-lived WAN links, when connecting to the internet on Linux 4.10
via an Android 7.0 hostapd Access Point (AP) gateway.
It is an unacceptable solution to have to manually kill wpa_supplicant &
dhclient & bring down the interface & start them all up again on timeouts -
especially as this was not necessary when my Linux 4.10 host connected via an
Android 4.2.2 device - 
many internet service applications (eg. BIND named) do not handle this situation correctly and spew error messages to the log and can get confused.
I'm thinking of adding a kernel boot parameter such as 
  wireless_ack_empty_frames=1
which will cause all empty frames to be ACK-ed instead of 
bringing down the link.
Why does the iwlwifi / 802.11 stack not complain loudly to 
the log when it brings down the network interface because of receipt of 
an empty data frame ?
Why doesn't wpa_supplicant notice the link has gone down like ntpd does?
I'm going to have to solve this myself if no WiFi developers will have a look -
I am not a wireless device expert - this is a problem better solved by
the experts - but I will have to fix it and publish a hack if they don't.

Comment 5 Luca Coelho 2017-03-21 20:24:05 UTC

You have reported the bug a couple of days ago.  We will look into it, don't worry.

Comment 6 Luca Coelho 2017-03-21 21:10:43 UTC

Okay, I've tried to connect my device with my phone running as an AP.  My phone is running LineageOS 14.1, which is based on Android 7.1.1.  It seems that I can reproduce your problem here as well.

The problem seems to occur a long time after the phone goes to sleep.  When I press the power key to wake it up, my ping continues working normally.

I'm going to try to take a sniffer capture of this situation to see what is going on, but from the look of it, I don't think it's our device that is not behaving correctly, but the Android side.

Comment 7 Luca Coelho 2017-03-21 21:36:46 UTC

I took a sniffer capture of this and I can clearly see that the phone (AP) stops responding to the ping requests after a while.  We keep trying to recover, sending NULL-data packets (NDPs) and the phone doesn't even ACK most of them.  Sometimes it ACKs the NDPs and we go ahead and send another ping request.  In most cases the AP ACKs the ping request data, but doesn't respond.

After I wake the phone, things seems to go back to normal.  I think this strengthens my hypothesis that the problem is in the phone side.  I'll try to reproduce the issue by connecting a non-iwlwifi device to the phone's AP.

Comment 8 Luca Coelho 2017-03-21 21:52:15 UTC

The problem does *not* happen (at least data continues flowing normally, at a first glance) with another phone.

Now I have some data, so we will continue investigating.  Thanks for the report!

Comment 9 Jason Vas Dias 2017-03-22 17:26:34 UTC

I had problems with connectivity in sleep mode too, until I 
set the setting
  WiFi -> Advanced -> Configuration -> Keep Wi-Fi on during sleep ->
  ( Always ) 
.
Now for me it makes no difference whether the phone is in sleep mode.
Unless you ping an external WAN host from the AP client, the 
 
  ap_max_inactivity=300

timeout comes into effect, and connectivity drops after @ 5mins.

There is some other 3600sec / 1 hour timeout which comes into
effect - I haven't found the setting for this.

But yes, first you have to set that WiFi Sleep Mode setting so
that the phone doesn't shut down comms during sleep.

I wish I could install lineageOS 14.1 - but my phone is not
easily rooted . That is the whole problem for me - if I could
root it, I could write my own /etc/hostapd/hostapd.conf 
and change the timeout settings.
I think you should try and get hold of an unrooted Android 7.0 
phone like mine and see what the rest of us have to put up with.
Thanks & Regards, Jason

Comment 10 Jason Vas Dias 2017-03-22 17:35:33 UTC

Note that the above does not mean I am turning WiFi 'On'  -
WiFi is 'Disabled', but that 
  Keep Wi-Fi on during sleep -> ( Always ) 
setting has meaning for the Wi-Fi HotSpot also.

Comment 11 Jason Vas Dias 2017-03-22 18:20:00 UTC

Aha! : 
/etc/hostapd/hostapd_default.conf on the Android 7.0 device (complete file
attached below) says:

# EAP reauthentication period in seconds (default: 3600 seconds; 0 = disable
# reauthentication).
#eap_reauth_period=3600

Surely, wpa_supplicant should be somehow aware of this ?

To me it is looking like the fix is in wpa_supplicant, to make it
do some 'keepalive' activity, to make it detect when the link 
goes down the same way ntpd does & automatically do a re-auth,
and to make it honor the eap_reauth_period properly - maybe
pass it some reauth_period=3600 parameter / configuration entry ?

Comment 12 Jason Vas Dias 2017-03-22 18:22:10 UTC

Created attachment 255435 [details]
/etc/hostapd/hostapd_default.conf from my un-rooted Android 7.0 device

/etc/hostapd/hostapd_default.conf from my un-rooted Android 7.0 device

Comment 13 Jason Vas Dias 2017-03-22 18:25:43 UTC

maybe the hourly timeout is :

# Number of seconds of no frames received after which entries may be deleted
# from the AP table. Since passive scanning is not usually performed frequently
# this should not be set to very small value. In addition, there is no
# guarantee that every scan cycle will receive beacon frames from the
# neighboring APs.
# default: 60
#ap_table_expiration_time=3600

Comment 14 Jason Vas Dias 2017-03-22 18:32:46 UTC

Note also that, as stated in the stackexchange & XDA-developers issues I raised
on this, there is weirdness going on with the AP client pinging the phone AP :
  pings of the AP (phone) from the AP client will time out while pings of an
  external internet host from the AP client will not.

Comment 15 Jason Vas Dias 2017-03-22 18:35:18 UTC

I cannot  even see the system log on the phone, even though I have
Android Studio & all NDK tools installed on the linux host - 
non root users are not allowed to see log messages in Android 7.0.

Comment 16 Jason Vas Dias 2017-03-22 18:37:38 UTC

I'm thinking of selling the phone on eBay and getting an older (rootable) model
because of this issue.

Comment 17 Jason Vas Dias 2017-03-22 18:39:37 UTC

Please can this bug just be about getting the timeout issues resolved (as it was originally) not attempting to solve the sleep mode issues or the ping timeout issues.

Comment 18 Jason Vas Dias 2017-03-22 18:47:19 UTC

Maybe in sleep mode, the phone does not respond to ping, but because WiFi HotSpot is active, and 'WiFi On During Sleep (ALWAYS)' is enabled, it still passes ICMP
on to the WAN in sleep mode.

Comment 19 Jason Vas Dias 2017-03-22 19:01:55 UTC

https://forum.xda-developers.com/general/networking/android-nougat-7-0-7-1-wifi-hotspot-t3574776
http://android.stackexchange.com/questions/171241/wifi-hotspot-timeout-setting-gone-in-nougat-7-0-7-1-but-timeout-has-not

Comment 20 Jason Vas Dias 2017-03-22 19:24:07 UTC

Aha! 'adb logcat' works!
even though no logs are accessable on phone.
I'll post back the logs when the next hourly timeout will occur
@ 19:29 this evening.

Comment 21 Jason Vas Dias 2017-03-22 19:51:39 UTC

The timeout kicked off as predicted @19:30, when 'adb logcat' was running:
<quote><pre>
03-22 19:30:38.115  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -99 -9 134 2147483647 2147483647 gsm|lte level=2
03-22 19:30:38.115  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -99 -9 134 2147483647 2147483647 gsm|lte
03-22 19:30:38.115  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-99 rsrpLevel = 3
03-22 19:30:38.118  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:30:38.119  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:30:38.119  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:30:38.119  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:38.119  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:30:38.119  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:38.122  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:38.124  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:38.126  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:38.128  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:38.506 11686 11686 V HardwareService: cpu  78650 8611 45385 3936563 38926 23 3900 0 0 0
03-22 19:30:38.506 11686 11686 D HardwareService: Current processor usage is 1.0049998743750157
03-22 19:30:38.793  1896  1984 D PowerManagerService: acquireWakeLockInternal: lock=123945203, flags=0x1, tag="*alarm*", ws=WorkSource{10012}, uid=1000, pid=1896
03-22 19:30:38.795  1896  6263 D PowerManagerService: acquireWakeLockInternal: lock=27571239, flags=0x1, tag="NlpWakeLock", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:38.796  1896  6072 D WifiService: acquireWifiLockLocked: WifiLock{NlpWifiLock type=2 uid=10012}
03-22 19:30:38.807  1896  1896 D PowerManagerService: releaseWakeLockInternal: lock=123945203 [*alarm*], flags=0x00, total_time=14ms
03-22 19:30:38.808  1896  2563 D PowerManagerService: acquireWakeLockInternal: lock=174808182, flags=0x1, tag="RILJ", ws=null, uid=1001, pid=2360
03-22 19:30:38.821  1896  4392 D PowerManagerService: releaseWakeLockInternal: lock=174808182 [RILJ], flags=0x00, total_time=14ms
03-22 19:30:38.823  1896  2365 D PowerManagerService: acquireWakeLockInternal: lock=254182007, flags=0x1, tag="RILJ", ws=null, uid=1001, pid=2360
03-22 19:30:38.846  1896  2401 D PowerManagerService: releaseWakeLockInternal: lock=254182007 [RILJ], flags=0x00, total_time=23ms
03-22 19:30:38.864 11686 11686 V HardwareService: cpu  78651 8614 45386 3936702 38926 23 3900 0 0 0
03-22 19:30:38.864 11686 11686 D HardwareService: Current processor usage is 2.255582566852961
03-22 19:30:39.507 11686 11686 V HardwareService: cpu  78651 8614 45386 3936959 38926 23 3900 0 0 0
03-22 19:30:39.507 11686 11686 D HardwareService: Current processor usage is 1.2468516994588663
03-22 19:30:39.864 11686 11686 V HardwareService: cpu  78652 8614 45386 3937101 38926 23 3900 0 0 0
03-22 19:30:39.864 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:40.508 11686 11686 V HardwareService: cpu  78652 8614 45386 3937358 38926 23 3900 0 0 0
03-22 19:30:40.508 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:40.865 11686 11686 V HardwareService: cpu  78652 8614 45387 3937500 38926 23 3900 0 0 0
03-22 19:30:40.865 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:41.508 11686 11686 V HardwareService: cpu  78652 8614 45387 3937757 38926 23 3900 0 0 0
03-22 19:30:41.508 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:41.865 11686 11686 V HardwareService: cpu  78652 8614 45388 3937899 38926 23 3900 0 0 0
03-22 19:30:41.865 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:42.508 11686 11686 V HardwareService: cpu  78652 8614 45389 3938155 38926 23 3900 0 0 0
03-22 19:30:42.509 11686 11686 D HardwareService: Current processor usage is 0.49998750031249223
03-22 19:30:42.866 11686 11686 V HardwareService: cpu  78652 8614 45389 3938298 38926 23 3900 0 0 0
03-22 19:30:42.866 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:43.509 11686 11686 V HardwareService: cpu  78652 8614 45390 3938554 38926 23 3900 0 0 0
03-22 19:30:43.509 11686 11686 D HardwareService: Current processor usage is 0.24999375015624611
03-22 19:30:43.516  1896  3234 D BatteryService: Processing new values: chargerAcOnline=true, chargerUsbOnline=false, chargerWirelessOnline=false, maxChargingCurrent0, maxChargingVoltage0, chargeCounter0, batteryStatus=5, batteryHealth=2, batteryPresent=true, batteryLevel=100, batteryTechnology=, batteryVoltage=4203, batteryTemperature=170, mBatteryLevelCritical=false, mPlugType=1
03-22 19:30:43.516  1896  3234 D BatteryService: Sending ACTION_BATTERY_CHANGED.  level:100, scale:100, status:5, health:2, present:true, voltage: 4203, temperature: 170, technology: , AC powered:true, USB powered:false, Wireless powered:false, icon:17303289, invalid charger:0, maxChargingCurrent:0, maxChargingVoltage:0, chargeCounter:0
03-22 19:30:43.516  1896  3234 W BatteryService: updateLightsLocked level : 100 , status : 5 , mLowBatteryWarningLevel : 15 , mNotificationChargingEnabled : true
03-22 19:30:43.518  2123  2123 D KeyguardUpdateMonitor: received broadcast android.intent.action.BATTERY_CHANGED
03-22 19:30:43.519  2990  3074 W QCNEJ   : |CORE| CNE received unexpected action: android.intent.action.BATTERY_CHANGED
03-22 19:30:43.519  1896  1896 I BasicWindowManager:  CurrentBatterylevel is 100
03-22 19:30:43.519  1896  1896 D UsbDeviceManager: onReceive - mUsbNotificationId == charging ? true, mSettingUsbCharging: true mPlugType = 1 mConnected = true mCurrentFunctions = charging,adb
03-22 19:30:43.520  3477  3477 D NightModeService: Intent.ACTION_BATTERY_CHANGED received
03-22 19:30:43.521  3477  3477 D NightModeService: init location manager to get location information.
03-22 19:30:43.521  2123  2123 D BatteryUI: onBatteryLevelChanged - level = 100
03-22 19:30:43.521  3477  3477 D NightModeService: sunrise/sunset mode not setted, no need to get location info.
03-22 19:30:43.524  2123  2123 D BatteryUI: onBatteryLevelChanged - mShow = true
03-22 19:30:43.525  2123  2123 D BatteryUI: onBatteryLevelChanged - level = 100
03-22 19:30:43.529  2123  2123 D BatteryUI: onBatteryLevelChanged - mShow = true
03-22 19:30:43.531  2123  2123 D KeyguardUpdateMonitor: handleBatteryUpdate
03-22 19:30:43.531  2123  2708 D BatteryTile: handleUpdateState: arg = 100, mLevel = 100
03-22 19:30:43.540  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:43.542  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:43.545  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:43.547  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:43.550  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:43.552  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:43.554  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:43.555  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:43.803  1896  1984 D PowerManagerService: acquireWakeLockInternal: lock=123945203, flags=0x1, tag="*alarm*", ws=WorkSource{10012}, uid=1000, pid=1896
03-22 19:30:43.804  1896  2365 D PowerManagerService: acquireWakeLockInternal: lock=108349807, flags=0x1, tag="NlpWakeLock", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.810  1896  2382 D PowerManagerService: releaseWakeLockInternal: lock=108349807 [NlpWakeLock], flags=0x00, total_time=5ms
03-22 19:30:43.812  1896  6260 D PowerManagerService: acquireWakeLockInternal: lock=217120948, flags=0x1, tag="NlpWakeLock", ws=null, uid=10012, pid=2961
03-22 19:30:43.816  1896  6266 D PowerManagerService: releaseWakeLockInternal: lock=217120948 [NlpWakeLock], flags=0x00, total_time=4ms
03-22 19:30:43.818  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=35993787, flags=0x1, tag="LocationManagerService", ws=WorkSource{1000 com.qualcomm.location}, uid=1000, pid=1896
03-22 19:30:43.818  1896  3119 D PowerManagerService: releaseWakeLockInternal: lock=35993787 [LocationManagerService], flags=0x00, total_time=1ms
03-22 19:30:43.819  1896  3119 V OSNPGlue_jni: Entering  : void onJavaLocationChanged(JNIEnv *, jobject, jboolean, jlong, jboolean, jlong, jboolean, jdouble, jboolean, jdouble, jboolean, jfloat, jboolean, jdouble, jboolean, jfloat, jboolean, jfloat, jboolean, jint)
03-22 19:30:43.819  1896  6265 D PowerManagerService: acquireWakeLockInternal: lock=808157, flags=0x1, tag="NlpWakeLock", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.820  1896  3135 E LocSvc_libulp: E/int ulp_brain_transition_all_providers(), no QUIPC/GNSS transition logic run due to both engines are OFF 
03-22 19:30:43.823  1896  4391 D PowerManagerService: releaseWakeLockInternal: lock=808157 [NlpWakeLock], flags=0x00, total_time=4ms
03-22 19:30:43.824  1896  3196 D PowerManagerService: acquireWakeLockInternal: lock=118073426, flags=0x1, tag="GCoreFlp", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.825  1896  2065 D PowerManagerService: releaseWakeLockInternal: lock=118073426 [GCoreFlp], flags=0x00, total_time=1ms
03-22 19:30:43.825  1896  4390 D PowerManagerService: acquireWakeLockInternal: lock=30529315, flags=0x1, tag="GCoreFlp", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.827  1896  2382 D PowerManagerService: acquireWakeLockInternal: lock=234320928, flags=0x1, tag="GCoreFlp", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.827  1896  3235 D WifiService: releaseWifiLockLocked: WifiLock{NlpWifiLock type=2 uid=10012}
03-22 19:30:43.828  1896  1907 D PowerManagerService: acquireWakeLockInternal: lock=108394398, flags=0x1, tag="GCoreFlp", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.829  1896  1906 D PowerManagerService: releaseWakeLockInternal: lock=27571239 [NlpWakeLock], flags=0x00, total_time=5033ms
03-22 19:30:43.830  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=89579326, flags=0x1, tag="LocationManagerService", ws=WorkSource{1000 android}, uid=1000, pid=1896
03-22 19:30:43.830  1896  6266 D PowerManagerService: acquireWakeLockInternal: lock=65061503, flags=0x1, tag="CMWakeLock", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.831  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=100016543, flags=0x1, tag="LocationManagerService", ws=WorkSource{1000 android}, uid=1000, pid=1896
03-22 19:30:43.831  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=35993787, flags=0x1, tag="LocationManagerService", ws=WorkSource{1000 com.qualcomm.location}, uid=1000, pid=1896
03-22 19:30:43.832  1896  6263 D PowerManagerService: acquireWakeLockInternal: lock=106792014, flags=0x1, tag="GCoreFlp", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.832  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=69422229, flags=0x1, tag="LocationManagerService", ws=WorkSource{10012 com.google.android.gms}, uid=1000, pid=1896
03-22 19:30:43.833  1896  1908 D PowerManagerService: acquireWakeLockInternal: lock=123209777, flags=0x1, tag="LocationManagerService", ws=WorkSource{10012 com.google.android.gms}, uid=1000, pid=1896
03-22 19:30:43.834  1896  1896 D PowerManagerService: releaseWakeLockInternal: lock=89579326 [LocationManagerService], flags=0x00, total_time=4ms
03-22 19:30:43.834  1896  1896 D PowerManagerService: releaseWakeLockInternal: lock=123945203 [*alarm*], flags=0x00, total_time=31ms
03-22 19:30:43.835  1896  3119 D PowerManagerService: releaseWakeLockInternal: lock=35993787 [LocationManagerService], flags=0x00, total_time=3ms
03-22 19:30:43.835  1896  1908 D PowerManagerService: releaseWakeLockInternal: lock=100016543 [LocationManagerService], flags=0x00, total_time=4ms
03-22 19:30:43.835  1896  4391 D PowerManagerService: releaseWakeLockInternal: lock=123209777 [LocationManagerService], flags=0x00, total_time=3ms
03-22 19:30:43.848  1896  4390 D PowerManagerService: releaseWakeLockInternal: lock=106792014 [GCoreFlp], flags=0x00, total_time=16ms
03-22 19:30:43.849  1896  2365 D PowerManagerService: acquireWakeLockInternal: lock=254784076, flags=0x1, tag="Wakeful StateMachine: GeofencerStateMachine", ws=WorkSource{10012 com.google.android.gms}, uid=10012, pid=2961
03-22 19:30:43.851  2961  3287 W ctxmgr  : [AclManager]No 2 for (accnt=account#271539201#, com.google.android.gms(10012):UserLocationProducer, vrsn=10298000, 0, 3pPkg = null ,  3pMdlId = null). Was: 2 for 1, account#271539201#
03-22 19:30:43.855  1896  4391 D PowerManagerService: releaseWakeLockInternal: lock=65061503 [CMWakeLock], flags=0x00, total_time=25ms
03-22 19:30:43.859  1896  3235 D PowerManagerService: releaseWakeLockInternal: lock=30529315 [GCoreFlp], flags=0x00, total_time=33ms
03-22 19:30:43.860  1896  6266 D PowerManagerService: releaseWakeLockInternal: lock=234320928 [GCoreFlp], flags=0x00, total_time=33ms
03-22 19:30:43.863  1896  4391 D PowerManagerService: releaseWakeLockInternal: lock=108394398 [GCoreFlp], flags=0x00, total_time=34ms
03-22 19:30:43.864  1896  4392 D PowerManagerService: releaseWakeLockInternal: lock=69422229 [LocationManagerService], flags=0x00, total_time=31ms
03-22 19:30:43.870 11686 11686 V HardwareService: cpu  78663 8617 45401 3938673 38926 23 3900 0 0 0
03-22 19:30:43.871 11686 11686 D HardwareService: Current processor usage is 6.483628837186105
03-22 19:30:43.889  1896  2401 D PowerManagerService: releaseWakeLockInternal: lock=254784076 [Wakeful StateMachine: GeofencerStateMachine], flags=0x00, total_time=40ms
03-22 19:30:44.509 11686 11686 V HardwareService: cpu  78665 8617 45403 3938887 38964 23 3900 0 0 0
03-22 19:30:44.509 11686 11686 D HardwareService: Current processor usage is 16.74958126046849
03-22 19:30:44.869 11686 11686 V HardwareService: cpu  78665 8617 45404 3939031 38964 23 3900 0 0 0
03-22 19:30:44.869 11686 11686 D HardwareService: Current processor usage is 10.722924615346251
03-22 19:30:45.509 11686 11686 V HardwareService: cpu  78666 8617 45404 3939285 38964 23 3900 0 0 0
03-22 19:30:45.509 11686 11686 D HardwareService: Current processor usage is 0.49998750031249223
03-22 19:30:45.869 11686 11686 V HardwareService: cpu  78666 8617 45405 3939429 38964 23 3900 0 0 0
03-22 19:30:45.869 11686 11686 D HardwareService: Current processor usage is 0.49998750031249223
03-22 19:30:46.510 11686 11686 V HardwareService: cpu  78667 8617 45405 3939685 38964 23 3900 0 0 0
03-22 19:30:46.510 11686 11686 D HardwareService: Current processor usage is 0.49750006218750775
03-22 19:30:46.870 11686 11686 V HardwareService: cpu  78667 8617 45406 3939828 38964 23 3900 0 0 0
03-22 19:30:46.870 11686 11686 D HardwareService: Current processor usage is 0.4987406797835466
03-22 19:30:47.089  1896  9243 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xa
03-22 19:30:47.132  1896  9243 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xa
03-22 19:30:47.140  1896  9243 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xa
03-22 19:30:47.211  1896  2563 D PowerManagerService: acquireWakeLockInternal: lock=246630953, flags=0x1, tag="RILJ_ACK_WL", ws=null, uid=1001, pid=2360
03-22 19:30:47.220  2123  2491 D NetworkController.MobileSignalController(1): onDataActivity: direction=4
03-22 19:30:47.223  2123  2491 D NetworkController.MobileSignalController(1): onDataActivity: direction=0
03-22 19:30:47.281   329  1266 E NetlinkEvent: NetlinkEvent::FindParam(): Parameter 'UID' not found
03-22 19:30:47.395  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d IEEE 802.11: associated
03-22 19:30:47.395  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d IEEE 802.11: associated
03-22 19:30:47.409  9247  9247 I hostapd : wlan0: AP-STA-CONNECTED f8:16:54:f7:d6:6d
03-22 19:30:47.409  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d WPA: pairwise key handshake completed (RSN)
03-22 19:30:47.409  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d WPA: pairwise key handshake completed (RSN)
03-22 19:30:47.412  1896  6264 D PowerManagerService: releaseWakeLockInternal: lock=246630953 [RILJ_ACK_WL], flags=0x00, total_time=201ms
03-22 19:30:47.510 11686 11686 V HardwareService: cpu  78669 8617 45409 3940077 38964 23 3900 0 0 0
03-22 19:30:47.510 11686 11686 D HardwareService: Current processor usage is 1.5074998115625236
03-22 19:30:47.523   329  9248 D SoftapController: Get event from hostapd (<3>AP-STA-CONNECTED f8:16:54:f7:d6:6d)
03-22 19:30:47.524  1896  1914 D NetworkManagement: onEvent: 618 278 IfaceMessage active <3>AP-STA-CONNECTED f8:16:54:f7:d6:6d
03-22 19:30:47.543   333   333 I cnss-daemon: RTM_NEWROUTE Indication
03-22 19:30:47.583   333   333 I cnss-daemon: RTM_NEWROUTE Indication
03-22 19:30:47.870 11686 11686 V HardwareService: cpu  78669 8617 45409 3940220 38964 23 3900 0 0 0
03-22 19:30:47.870 11686 11686 D HardwareService: Current processor usage is 1.2594141205511196
03-22 19:30:48.035  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 22 -95 -7 202 2147483647 2147483647 gsm|lte level=3
03-22 19:30:48.035  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 22 -95 -7 202 2147483647 2147483647 gsm|lte
03-22 19:30:48.036  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-95 rsrpLevel = 4
03-22 19:30:48.039  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:30:48.040  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:30:48.040  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:30:48.040  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:48.040  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:30:48.040  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:48.041  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:48.043  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:48.045  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:48.047  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:48.256  9257  9257 I dnsmasq : DHCPDISCOVER(wlan0) 192.168.43.124 f8:16:54:f7:d6:6d 
03-22 19:30:48.256  9257  9257 I dnsmasq : DHCPOFFER(wlan0) 192.168.43.124 f8:16:54:f7:d6:6d 
03-22 19:30:48.256  9257  9257 W dnsmasq : Ignoring domain jvds.net for DHCP host name (null)
03-22 19:30:48.275  9257  9257 I dnsmasq : DHCPREQUEST(wlan0) 192.168.43.124 f8:16:54:f7:d6:6d 
03-22 19:30:48.275  9257  9257 I dnsmasq : DHCPACK(wlan0) 192.168.43.124 f8:16:54:f7:d6:6d jvdlux
03-22 19:30:48.275  9257  9257 W dnsmasq : Ignoring domain jvds.net for DHCP host name jvdlux
03-22 19:30:48.510 11686 11686 V HardwareService: cpu  78669 8617 45413 3940468 38966 23 3900 0 0 0
03-22 19:30:48.510 11686 11686 D HardwareService: Current processor usage is 1.5112969446613436
03-22 19:30:48.632   333   333 I cnss-daemon: RTM_NEWROUTE Indication
03-22 19:30:48.871 11686 11686 V HardwareService: cpu  78669 8617 45413 3940612 38966 23 3900 0 0 0
03-22 19:30:48.871 11686 11686 D HardwareService: Current processor usage is 1.5074998115625236
03-22 19:30:49.510 11686 11686 V HardwareService: cpu  78669 8617 45413 3940865 38967 23 3900 0 0 0
03-22 19:30:49.510 11686 11686 D HardwareService: Current processor usage is 0.2512499685937539
03-22 19:30:49.657  1896  1984 D PowerManagerService: acquireWakeLockInternal: lock=123945203, flags=0x1, tag="*alarm*", ws=WorkSource{10091}, uid=1000, pid=1896
03-22 19:30:49.669  1896  1896 D PowerManagerService: releaseWakeLockInternal: lock=123945203 [*alarm*], flags=0x00, total_time=11ms
03-22 19:30:49.870 11686 11686 V HardwareService: cpu  78670 8617 45415 3941006 38967 23 3900 0 0 0
03-22 19:30:49.870 11686 11686 D HardwareService: Current processor usage is 1.0049998743750157
03-22 19:30:50.273  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 20 -100 -7 144 2147483647 2147483647 gsm|lte level=2
03-22 19:30:50.273  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 20 -100 -7 144 2147483647 2147483647 gsm|lte
03-22 19:30:50.274  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-100 rsrpLevel = 3
03-22 19:30:50.278  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:30:50.278  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:30:50.278  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:30:50.278  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:50.278  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:30:50.278  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:50.281  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:50.282  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:50.284  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:50.286  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:50.510 11686 11686 V HardwareService: cpu  78670 8619 45415 3941255 38967 23 3900 0 0 0
03-22 19:30:50.510 11686 11686 D HardwareService: Current processor usage is 1.26579073947495
03-22 19:30:50.871 11686 11686 V HardwareService: cpu  78670 8619 45417 3941399 38967 23 3900 0 0 0
03-22 19:30:50.871 11686 11686 D HardwareService: Current processor usage is 1.0075312964408956
03-22 19:30:51.511 11686 11686 V HardwareService: cpu  78670 8619 45417 3941654 38967 23 3900 0 0 0
03-22 19:30:51.511 11686 11686 D HardwareService: Current processor usage is 0.4987406797835466
03-22 19:30:51.871 11686 11686 V HardwareService: cpu  78670 8619 45417 3941797 38967 23 3900 0 0 0
03-22 19:30:51.871 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:52.511 11686 11686 V HardwareService: cpu  78670 8619 45417 3942052 38967 23 3900 0 0 0
03-22 19:30:52.511 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:52.871 11686 11686 V HardwareService: cpu  78670 8619 45417 3942196 38967 23 3900 0 0 0
03-22 19:30:52.871 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:53.511 11686 11686 V HardwareService: cpu  78670 8619 45417 3942451 38967 23 3900 0 0 0
03-22 19:30:53.511 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:53.872 11686 11686 V HardwareService: cpu  78670 8619 45417 3942596 38967 23 3900 0 0 0
03-22 19:30:53.872 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:54.512 11686 11686 V HardwareService: cpu  78670 8619 45417 3942851 38967 23 3900 0 0 0
03-22 19:30:54.512 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:30:54.872 11686 11686 V HardwareService: cpu  78670 8619 45417 3942993 38968 23 3900 0 0 0
03-22 19:30:54.872 11686 11686 D HardwareService: Current processor usage is 0.2512499685937539
03-22 19:30:55.398   333   333 I cnss-daemon: RTM_NEWNEIGH message received: 28
03-22 19:30:55.398   333   333 I cnss-daemon: NDA_DST received: 192.168.43.124 ul: 562994986330304
03-22 19:30:55.398   333   333 I cnss-daemon: NDA_LLADDR received
03-22 19:30:55.398   333   333 E cnss-daemon: gateway mac address: %02x:%02x:%02x:%02x:%02x:%02x
03-22 19:30:55.398   333   333 E cnss-daemon: : 00:00:00:00:00:00
03-22 19:30:55.398   333   333 E cnss-daemon: Invalid mac address: 0x5588705110M
03-22 19:30:55.512 11686 11686 V HardwareService: cpu  78670 8619 45417 3943247 38968 23 3900 0 0 0
03-22 19:30:55.512 11686 11686 D HardwareService: Current processor usage is 0.2518828241102239
03-22 19:30:55.872 11686 11686 V HardwareService: cpu  78678 8619 45417 3943383 38968 23 3900 0 0 0
03-22 19:30:55.872 11686 11686 D HardwareService: Current processor usage is 2.0099997487500314
03-22 19:30:55.893  1896  1896 V NotificationService: pkg=org.torproject.android canInterrupt=false intercept=false aboveThreshold : false current Importance 2
03-22 19:30:56.513 11686 11686 V HardwareService: cpu  78723 8619 45418 3943590 38969 23 3900 0 0 0
03-22 19:30:56.513 11686 11686 D HardwareService: Current processor usage is 13.818748272656467
03-22 19:30:56.873 11686 11686 V HardwareService: cpu  78723 8619 45419 3943733 38969 23 3900 0 0 0
03-22 19:30:56.873 11686 11686 D HardwareService: Current processor usage is 12.059998492500188
03-22 19:30:56.894  1896  1896 V NotificationService: pkg=org.torproject.android canInterrupt=false intercept=false aboveThreshold : false current Importance 2
03-22 19:30:57.185  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 23 -92 -7 170 2147483647 2147483647 gsm|lte level=3
03-22 19:30:57.185  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 23 -92 -7 170 2147483647 2147483647 gsm|lte
03-22 19:30:57.185  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-92 rsrpLevel = 4
03-22 19:30:57.189  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:30:57.189  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:30:57.189  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:30:57.189  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:57.190  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:30:57.190  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:57.191  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:57.193  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:57.196  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:57.197  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:57.513 11686 11686 V HardwareService: cpu  78728 8619 45422 3943974 38971 23 3900 0 0 0
03-22 19:30:57.513 11686 11686 D HardwareService: Current processor usage is 2.7847396268448903
03-22 19:30:57.874 11686 11686 V HardwareService: cpu  78728 8619 45422 3944118 38971 23 3900 0 0 0
03-22 19:30:57.874 11686 11686 D HardwareService: Current processor usage is 2.5315814789499
03-22 19:30:57.896  1896  1896 V NotificationService: pkg=org.torproject.android canInterrupt=false intercept=false aboveThreshold : false current Importance 2
03-22 19:30:58.514 11686 11686 V HardwareService: cpu  78743 8619 45425 3944354 38972 23 3900 0 0 0
03-22 19:30:58.514 11686 11686 D HardwareService: Current processor usage is 4.761785418911807
03-22 19:30:58.874 11686 11686 V HardwareService: cpu  78743 8619 45425 3944498 38972 23 3900 0 0 0
03-22 19:30:58.874 11686 11686 D HardwareService: Current processor usage is 4.761785418911807
03-22 19:30:58.895  1896  1896 V NotificationService: pkg=org.torproject.android canInterrupt=false intercept=false aboveThreshold : false current Importance 2
03-22 19:30:59.426  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -98 -8 92 2147483647 2147483647 gsm|lte level=2
03-22 19:30:59.426  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -98 -8 92 2147483647 2147483647 gsm|lte
03-22 19:30:59.426  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-98 rsrpLevel = 3
03-22 19:30:59.430  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:30:59.430  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:30:59.430  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:30:59.430  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:59.430  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:30:59.430  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:30:59.435  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:59.437  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:59.440  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:30:59.442  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:30:59.514 11686 11686 V HardwareService: cpu  78749 8620 45428 3944742 38973 23 3901 0 0 0
03-22 19:30:59.514 11686 11686 D HardwareService: Current processor usage is 2.9999250018749533
03-22 19:30:59.876 11686 11686 V HardwareService: cpu  78749 8620 45428 3944886 38973 23 3901 0 0 0
03-22 19:30:59.876 11686 11686 D HardwareService: Current processor usage is 2.9999250018749533
03-22 19:31:00.514 11686 11686 V HardwareService: cpu  78749 8620 45429 3945138 38973 23 3901 0 0 0
03-22 19:31:00.514 11686 11686 D HardwareService: Current processor usage is 0.2518828241102239
03-22 19:31:00.874 11686 11686 V HardwareService: cpu  78749 8620 45429 3945282 38973 23 3901 0 0 0
03-22 19:31:00.875 11686 11686 D HardwareService: Current processor usage is 0.2518828241102239
03-22 19:31:01.515 11686 11686 V HardwareService: cpu  78749 8620 45429 3945537 38973 23 3901 0 0 0
03-22 19:31:01.515 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:31:01.875 11686 11686 V HardwareService: cpu  78749 8620 45429 3945681 38973 23 3901 0 0 0
03-22 19:31:01.875 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:31:02.515 11686 11686 V HardwareService: cpu  78749 8620 45429 3945936 38973 23 3901 0 0 0
03-22 19:31:02.515 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:31:02.875 11686 11686 V HardwareService: cpu  78749 8620 45429 3946079 38973 23 3901 0 0 0
03-22 19:31:02.875 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:31:03.515 11686 11686 V HardwareService: cpu  78749 8620 45429 3946335 38973 23 3901 0 0 0
03-22 19:31:03.515 11686 11686 D HardwareService: Current processor usage is 0.0
03-22 19:31:03.553  1896  6074 D BatteryService: Processing new values: chargerAcOnline=true, chargerUsbOnline=false, chargerWirelessOnline=false, maxChargingCurrent0, maxChargingVoltage0, chargeCounter0, batteryStatus=5, batteryHealth=2, batteryPresent=true, batteryLevel=100, batteryTechnology=, batteryVoltage=4202, batteryTemperature=170, mBatteryLevelCritical=false, mPlugType=1
03-22 19:31:03.553  1896  6074 D BatteryService: Sending ACTION_BATTERY_CHANGED.  level:100, scale:100, status:5, health:2, present:true, voltage: 4202, temperature: 170, technology: , AC powered:true, USB powered:false, Wireless powered:false, icon:17303289, invalid charger:0, maxChargingCurrent:0, maxChargingVoltage:0, chargeCounter:0
03-22 19:31:03.553  1896  6074 W BatteryService: updateLightsLocked level : 100 , status : 5 , mLowBatteryWarningLevel : 15 , mNotificationChargingEnabled : true
03-22 19:31:03.556  1896  1896 I BasicWindowManager:  CurrentBatterylevel is 100
03-22 19:31:03.556  1896  1896 D UsbDeviceManager: onReceive - mUsbNotificationId == charging ? true, mSettingUsbCharging: true mPlugType = 1 mConnected = true mCurrentFunctions = charging,adb
03-22 19:31:03.558  2990  3074 W QCNEJ   : |CORE| CNE received unexpected action: android.intent.action.BATTERY_CHANGED
03-22 19:31:03.559  2123  2123 D KeyguardUpdateMonitor: received broadcast android.intent.action.BATTERY_CHANGED
03-22 19:31:03.560  3477  3477 D NightModeService: Intent.ACTION_BATTERY_CHANGED received
03-22 19:31:03.560  3477  3477 D NightModeService: init location manager to get location information.
03-22 19:31:03.561  3477  3477 D NightModeService: sunrise/sunset mode not setted, no need to get location info.
03-22 19:31:03.565  2123  2123 D BatteryUI: onBatteryLevelChanged - level = 100
03-22 19:31:03.568  2123  2123 D BatteryUI: onBatteryLevelChanged - mShow = true
03-22 19:31:03.569  2123  2123 D BatteryUI: onBatteryLevelChanged - level = 100
03-22 19:31:03.573  2123  2123 D BatteryUI: onBatteryLevelChanged - mShow = true
03-22 19:31:03.576  2123  2123 D KeyguardUpdateMonitor: handleBatteryUpdate
03-22 19:31:03.576  2123  2708 D BatteryTile: handleUpdateState: arg = 100, mLevel = 100
03-22 19:31:03.586  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:03.588  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:03.591  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:03.593  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:03.597  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:03.599  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:03.602  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:03.604  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:03.875 11686 11686 V HardwareService: cpu  78756 8622 45430 3946469 38973 23 3901 0 0 0
03-22 19:31:03.875 11686 11686 D HardwareService: Current processor usage is 2.499937501562461
03-22 19:31:03.905  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -99 -10 152 2147483647 2147483647 gsm|lte level=2
03-22 19:31:03.905  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 21 -99 -10 152 2147483647 2147483647 gsm|lte
03-22 19:31:03.905  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-99 rsrpLevel = 3
03-22 19:31:03.909  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:31:04.515 11686 11686 V HardwareService: cpu  78758 8622 45432 3946722 38973 23 3901 0 0 0
03-22 19:31:04.515 11686 11686 D HardwareService: Current processor usage is 3.4911847584848257
03-22 19:31:04.875 11686 11686 V HardwareService: cpu  78758 8622 45432 3946864 38974 23 3901 0 0 0
03-22 19:31:04.876 11686 11686 D HardwareService: Current processor usage is 1.2499687507812305
03-22 19:31:05.515 11686 11686 V HardwareService: cpu  78758 8622 45433 3947120 38974 23 3901 0 0 0
03-22 19:31:05.516 11686 11686 D HardwareService: Current processor usage is 0.49998750031249223
03-22 19:31:05.876 11686 11686 V HardwareService: cpu  78759 8622 45433 3947264 38974 23 3901 0 0 0
03-22 19:31:05.876 11686 11686 D HardwareService: Current processor usage is 0.49750006218750775
03-22 19:31:06.145  2123  2491 D NetworkController.MobileSignalController(1): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -120 -160 -120 -1 -1 25 -96 -11 158 2147483647 2147483647 gsm|lte level=2
03-22 19:31:06.145  2123  2491 D NetworkController.MobileSignalController(1): updateTelephony: hasService=true ss=SignalStrength: 99 0 -120 -160 -120 -1 -1 25 -96 -11 158 2147483647 2147483647 gsm|lte
03-22 19:31:06.145  2123  2491 D NetworkController.MobileSignalController(1): getAlternateLteLevel lteRsrp:-96 rsrpLevel = 4
03-22 19:31:06.148  2123  2491 D medion  : updateTelephony: mCurrentState.networkNameData = eir 4G
03-22 19:31:06.148  2123  2491 D MobileSignalController: dataDisabled = false
03-22 19:31:06.148  2123  2491 D MobileSignalController: dataActivity = 0
03-22 19:31:06.149  2123  2491 D MobileSignalController: qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:31:06.149  2123  2491 D MobileSignalController: activityIn = false, activityOut = false, mobileActivityId = 2130838759, icons.mActivityId = 0, dataConnected = true
03-22 19:31:06.149  2123  2491 D MobileSignalController: dataActivityId = 0, showDataIcon = true, showMobileActivity = true, typeIcon = com.android.systemui:drawable/stat_sys_data_fully_connected_4g, qsDataTypeIcon = com.android.systemui:drawable/ic_qs_signal_4g
03-22 19:31:06.150  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:06.152  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:06.154  2123  2123 D SignalClusterView: isMSim() = true
03-22 19:31:06.155  2123  2123 D SignalClusterView: MSim-getNoSimIcon mNoSimsVisible = false hasIccCard(0) = true hasIccCard(1) false
03-22 19:31:06.516 11686 11686 V HardwareService: cpu  78762 8623 45434 3947515 38974 23 3901 0 0 0
03-22 19:31:06.516 11686 11686 D HardwareService: Current processor usage is 1.4962220393506396
03-22 19:31:06.876 11686 11686 V HardwareService: cpu  78762 8623 45435 3947659 38974 23 3901 0 0 0
03-22 19:31:06.876 11686 11686 D HardwareService: Current processor usage is 1.4962220393506396
03-22 19:31:07.516 11686 11686 V HardwareService: cpu  78763 8623 45435 3947914 38974 23 3901 0 0 0
03-22 19:31:07.516 11686 11686 D HardwareService: Current processor usage is 0.4987406797835466
03-22 19:31:07.876 11686 11686 V HardwareService: cpu  78763 8623 45436 3948057 38974 23 3901 0 0 0
03-22 19:31:07.876 11686 11686 D HardwareService: Current processor usage is 0.49998750031249223

</pre></quote>



And on the AP client at the time, system logs showed 
(not time synced - haven't found how to make Android 7.0 
 use NTP yet) :

<quote><pre>
Mar 22 19:30:20 jvdlux ntpd[5695]: Deleting interface #12 wlp6s0, 192.168.43.124#123, interface stats: received=50, sent=56, dropped=0, active_time=3603 secs
Mar 22 19:30:20 jvdlux ntpd[5695]: 52.48.113.20 local addr 192.168.43.124 -> <null>
Mar 22 19:30:20 jvdlux ntpd[5695]: 52.209.118.149 local addr 192.168.43.124 -> <null>
Mar 22 19:30:20 jvdlux ntpd[5695]: 193.1.219.116 local addr 192.168.43.124 -> <null>
Mar 22 19:30:20 jvdlux ntpd[5695]: 178.79.152.182 local addr 192.168.43.124 -> <null>
Mar 22 19:30:23 jvdlux root: wlan_ping_monitor: ping 192.168.43.1 or 147.75.205.195 failed.
Mar 22 19:30:25 jvdlux last message repeated 2 times
Mar 22 19:30:26 jvdlux root: wlan_ping_monitor: interface  is down. Could not ping 192.168.43.1 or 147.75.205.195. Restarting Network...
Mar 22 19:30:26 jvdlux dhclient: Killed old client process
Mar 22 19:30:27 jvdlux dhclient: Internet Systems Consortium DHCP Client 4.3.5
...
Mar 22 19:30:27 jvdlux root: dhclient-script: DHCP Client set environment: old_subnet_mask=255.255.255.0 requested_host_name=1 old_domain_name_servers=127.0.0.1 old_broadcast_address=192.168.43.255 old_expiry=1490211027 requested_time_offset=1 interface=wlp6s0 reason=RELEASE old_dhcp_rebinding_time=3150 old_dhcp_message_type=5 PATH=/usr/sbin:/sbin:/bin:/usr/sbin:/usr/bin pid=11274 PWD=/ old_host_name=jvdlux requested_subnet_mask=1 requested_domain_name=1 SHLVL=1 requested_domain_name_servers=1 old_dhcp_server_identifier=192.168.43.1 old_ip_address=192.168.43.124 old_vendor_encapsulated_options=ANDROID_METERED old_dhcp_renewal_time=1800 old_dhcp_lease_time=3600 requested_broadcast_address=1 requested_routers=1 old_network_number=192.168.43.0 old_routers=192.168.43.1 _=/bin/env
Mar 22 19:30:28 jvdlux kernel: [10938.471872] wlp6s0: deauthenticating from 00:1a:95:a5:3b:40 by local choice (Reason: 3=DEAUTH_LEAVING)
Mar 22 19:30:28 jvdlux kernel: [10938.476548] wlp6s0: moving STA 00:1a:95:a5:3b:40 to state 3
Mar 22 19:30:28 jvdlux kernel: [10938.476650] wlp6s0: moving STA 00:1a:95:a5:3b:40 to state 2
Mar 22 19:30:28 jvdlux kernel: [10938.476656] wlp6s0: moving STA 00:1a:95:a5:3b:40 to state 1
Mar 22 19:30:28 jvdlux kernel: [10938.477151] wlp6s0: Removed STA 00:1a:95:a5:3b:40
Mar 22 19:30:28 jvdlux kernel: [10938.477260] wlp6s0: Destroyed STA 00:1a:95:a5:3b:40
Mar 22 19:30:29 jvdlux kernel: [10939.562324] r8169 0000:05:00.2 enp5s0f2: link down
Mar 22 19:30:29 jvdlux kernel: [10939.562390] IPv6: ADDRCONF(NETDEV_UP): enp5s0f2: link is not ready
Mar 22 19:30:30 jvdlux ntpd[5695]: Deleting interface #11 wlp6s0, fe80::fa16:54ff:fef7:d66d%3#123, interface stats: received=0, sent=0, dropped=0, active_time=3615 secs
Mar 22 19:30:31 jvdlux kernel: [10941.590607] iwlwifi 0000:06:00.0: L1 Disabled - LTR Disabled
Mar 22 19:30:31 jvdlux kernel: [10941.590858] iwlwifi 0000:06:00.0: L1 Disabled - LTR Disabled
Mar 22 19:30:31 jvdlux kernel: [10941.788556] iwlwifi 0000:06:00.0: L1 Disabled - LTR Disabled
Mar 22 19:30:31 jvdlux kernel: [10941.788792] iwlwifi 0000:06:00.0: L1 Disabled - LTR Disabled
Mar 22 19:30:31 jvdlux kernel: [10941.803782] IPv6: ADDRCONF(NETDEV_UP): wlp6s0: link is not ready
,,,
Mar 22 19:30:50 jvdlux dhclient: bound to 192.168.43.124 -- renewal in 1520 seconds.
Mar 22 19:30:50 jvdlux root: wlan_ping_monitor : started.
Mar 22 19:30:51 jvdlux ntpd[5695]: Listen normally on 14 wlp6s0 192.168.43.124:123
Mar 22 19:30:51 jvdlux ntpd[5695]: new interface(s) found: waking up resolver


</pre></quote>

Comment 22 Jason Vas Dias 2017-03-22 20:12:25 UTC

So I think the key events are :

1.

03-22 19:30:25.148   333   333 I cnss-daemon: RTM_NEWNEIGH message received: 28
03-22 19:30:25.148   333   333 E cnss-daemon: Stale or unreachable neighbors, ndm state: 4
...
03-22 19:30:28.507  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d IEEE 802.11: disassociated
03-22 19:30:28.508  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d IEEE 802.11: disassociated
03-22 19:30:28.508  9247  9247 I hostapd : wlan0: AP-STA-DISCONNECTED f8:16:54:f7:d6:6d
...
03-22 19:30:29.108   329  1266 E NetlinkEvent: NetlinkEvent::FindParam(): Parameter 'UID' not found
03-22 19:30:29.369  1896  9243 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xa

So that is why link goes down once per hour - somehow,
even though we were connected, an audio stream playing,
pings going on , etc. cnss thinks we are a 'stale or unreachable neighbor'
and disconnects us.

Comment 23 Jason Vas Dias 2017-03-22 20:15:22 UTC

Created attachment 255437 [details]
'adb logcat' from USB connected AP, from @8mins before disconnect, showing disconnect & reconnect

Comment 24 Jason Vas Dias 2017-03-22 21:09:47 UTC

Actually, there is nothing in the log as to WHY hostapd logs
'03-22 19:30:28.507  9247  9247 I hostapd : wlan0: STA f8:16:54:f7:d6:6d IEEE 802.11: disassociated' message; just that it is.
I'll try to generate more verbose wpa_supplicant & kernel wifi debugging -
I can't believe nothing in wpa_supplicant or the wifi drivers knows that
the link has gone down / been dropped by the AP - something on the
client wireless stack should be logging a message when this happens.

Comment 25 Luca Coelho 2017-10-12 11:00:20 UTC

Did you manage to find anything more about this issue?

This doesn't seem to be related to the driver itself, but either to the wpa_s or the AP side... since there's not much I can do here, I'm marking it as resolved and will close it soon, unless we get some more information.

Comment 26 Luca Coelho 2017-10-13 08:49:17 UTC

As I said yesterday, I'm closing this.  Please reopen if you find some proof that the problem is in the kernel side.