Stuck location

[licaon-kter]

Server/app at e0918f2

Been at one interior location for a while so it wasn't that odd that I had no update, but I've eventually exited, yet no update until expiration 30 mins later.

Logcat said

V info.varden.hauk: .service.LocationPushService.onLocationChanged(LocationPushService.java:195): Sending location update packet
V info.varden.hauk: .http.Packet.send(Packet.java:80): Sending packet of type info.varden.hauk.service.LocationPushService$LocationUpdatePacketImpl
V info.varden.hauk: .service.LocationPushService$2.onLocationChanged(LocationPushService.java:145): Location was received on fine location provider
...

...every 3 sec, as expected

GPS Test was tracking my location just fine.

Refreshed the browser and ever tried another ane, no joy.

How do I query redis to find out if coords are updated?

[bilde2910]

That's strange. I'll have to try and reproduce this myself (I mostly use memcached for testing). How long do you estimate you were indoors? I can simulate location being unavailable for a while and see how Redis responds to that.

You could always double check that your web server has the requests in its access log as POSTs to /api/post.php, but I don't see how this could not be a backend issue.

That said it's interesting that #69 occurs at the same time. I'll have to dig into this.

[bilde2910]

Additional logging set up in #106, also see my comment to #105 for this as it may be related.

[licaon-kter]

I had duration setup as 256mins, interval 3s, I was indoor about 3h.

I did take a look at logcat, but I was on the move and forgot to make a screenshot, but it "looked kinda like" this one #69 (comment) hence my snippet above, maybe it did say something else.

I keep forgetting to check the webserver logs, so here's that log:
hauk.host_access.log.zip
I was indoor from about 09:50 `till 12:40, then outdoor (GPS test was following me just fine then) until expiration.

The server is mostly idle, no errors in redis log.

[bilde2910]

According to your logs, it stopped sending data at 10:02:52 UTC and never started again. That's strange. The client just never sends it. I just don't understand what's going on here. I'm completely lost.

Do you have any web application firewalls between the app and server? Something that could drop the connection based on traffic analysis? Or is the backend directly exposed to the Internet?

[licaon-kter]

I do have Netguard, local VPN based firewall, so I need to test with Hauk excepted too, not only allowed.

Eg. I do see apps disconnecting while in background, but once in foreground they reconnect ok, hence Hauk, if affected by this (actually affected by the ROM killing the VPN connection hence cutting Hauk), should just re-connect fine when the screen is opened.

[bilde2910]

I installed Netguard just to test. Blocked Hauk manually, and I can reproduce the issue. I only see the three lines that it sends a packet, but no response is received. After the timeout interval, the status changes to "Unable to reach backend server". Another interesting thing I noticed is that as soon as I unblock Hauk, it sends all of the pending requests at the same time. The access log looks like this:

Access log

10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:18 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:19 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:20 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34
10.1.15.8 - - [15/Dec/2019:14:57:21 +0100] "POST /api/post.php HTTP/1.1" 200 34

It would be cool if you try exempting Hauk and see if that works. My guess is that Netguard causes this somehow.

[licaon-kter]

My setup in Netguard: Hauk allowed (actually only the server host is allowed but you can't do this with the free version), settings advanced filtering ON, so the internal Netguard TCP stack is used, versus filtering OFF (as you tested I guess) when only the Android VPN routing is used.

[bilde2910]

Tried setting "filter traffic" to on, same thing happens. Can you try temporarily disabling Netguard when this happens next time and see the location updates on the map then?

[licaon-kter]

Will try.

[licaon-kter]

Didn't see it lately, will reopen as needed.