Alarm ping sender and keepaliveinterval don't work.

[kazixma]

Please fill out the form below before submitting, thank you!

• [x] Bug exists Release Version 1.1.0 (Java Repository Master Branch)
• [ ] Bug exists in Snapshot Version 1.1.1-SNAPSHOT (Android Service Repository Master Branch)
• [ ] Bug is just in the Sample Application.

__Android API Version Bug Seen on:__23

__Android Version Bug Seen on:__Mashmallow

Please also check that if you have found the bug in the Release version (1.1.0) that you check that it also exists in the Snapshot (1.1.1-SNAPSHOT) before raising a bug.

Description of Bug:

I set keepaliveinterval 30 seconds when 30 seconds ago my connection is lost. And alarm ping sender don't send ping and unregister

Console Log output (if available):

07-20 11:24:53.371 9729-9776/com.example.bestiize.chatmqtt2 I/System.out: [socket][/192.168.0.108:50738] connected 07-20 11:24:53.476 9729-9800/com.example.bestiize.chatmqtt2 D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.besttize 07-20 11:24:53.477 9729-9800/com.example.bestiize.chatmqtt2 D/AlarmPingSender: Schedule next alarm at 1468988703477 07-20 11:25:08.583 9729-9800/com.example.bestiize.chatmqtt2 I/System.out: close [socket][/192.168.0.108:50738] 07-20 11:25:08.633 9729-9800/com.example.bestiize.chatmqtt2 D/AlarmPingSender: Unregister alarmreceiver to MqttServicebesttize 07-20 11:25:08.655 9729-9729/com.example.bestiize.chatmqtt2 D/connecting: lostConnection lost

Thankyou sir @jpwsutton

[jpwsutton]

This is interesting, I've got a barebones application that I use to test things like this (It's the paho.mqtt.android.example app in the repository). I just started it up and it worked fine:

07-21 10:56:04.280 6391-6675/paho.mqtt.java.example D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.ExampleAndroidClient
07-21 10:56:04.285 6391-6675/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469095024285
07-21 10:56:04.405 6391-6391/paho.mqtt.java.example I/System.out: LOG: Connected to: tcp://iot.eclipse.org:1883
07-21 10:56:04.469 6391-6391/paho.mqtt.java.example I/System.out: LOG: Subscribed!
07-21 10:57:04.285 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Ping 1 times.
07-21 10:57:04.285 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Check time :1469095024285
07-21 10:57:04.287 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469095084287
07-21 10:57:04.558 6391-6677/paho.mqtt.java.example D/AlarmPingSender: Success. Release lock(MqttService.client.ExampleAndroidClient):1469095024558
07-21 10:58:04.292 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Ping 1 times.
07-21 10:58:04.292 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Check time :1469095084292
07-21 10:58:04.305 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469095144305
07-21 10:58:04.504 6391-6677/paho.mqtt.java.example D/AlarmPingSender: Success. Release lock(MqttService.client.ExampleAndroidClient):1469095084504
07-21 10:59:04.307 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Ping 1 times.
07-21 10:59:04.307 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Check time :1469095144307
07-21 10:59:04.314 6391-6391/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469095204314
07-21 10:59:04.889 6391-6677/paho.mqtt.java.example D/AlarmPingSender: Success. Release lock(MqttService.client.ExampleAndroidClient):1469095144889

Just a few questions:

• Did you see this in the emulator or on a real device?
• If it was a real device, was it connected to the broker via wifi or cellular?
• What MQTT Broker are you using?

[kazixma]

@jpwsutton Did you see this in the emulator or on a real device? -Yes, I use real device. If it was a real device, was it connected to the broker via wifi or cellular? -I connect with wifi. What MQTT Broker are you using? -I use my server that MQTT broker , I use websocket protocol.

---

One question? Can Mqtt version 1.0.2 use setkeepaliveinterval ?

Thankyou @jpwsutton

[kazixma]

Ok I know it , because I use android 6.0 for test , And I fix this problem by change alarmpingsender .

alarmManager.setExactAndAllowWhileIdle(AlarmManager.RTC_WAKEUP, SystemClock.elapsedRealtime() + (delayInMilliseconds), pendingIntent);

credit by https://github.com/craxidile

Thankyou @jpwsutton

[jpwsutton]

Ok, here is some more info on this as I was having trouble recreating this:

I tried this on my Nexus 5 whilst tethered to look at the logs and couldn't reproduce. This is because whilst charging and being used, the phone does not go into idle mode. (More info about idle mode here: https://plus.google.com/+AndroidDevelopers/posts/94jCkmG4jff)

setExactAndAllowWhileIdle should allow us to work around this. However It's lead me to read into more info about Alarms and have found this article (https://plus.google.com/+AndroidDevelopers/posts/GdNrQciPwqo?linkId=17112180) and this flowchart (https://plus.google.com/photos/+AndroidDevelopers/albums/6192956247815306001/6192956249638257586?pid=6192956249638257586&oid=108967384991768947849)

This makes it look like Alarms might not actually the best things to be using for scheduling pings. However re-inventing the AlarmPingSender might be fairly destructive and it would need to still work with API 9 and above.. More thought is needed here I think..

For now, this change looks good, I'll add it in along with the correct checks so that it doesn't break backwards compatibility.

[binarybucks]

Please note that setExactAndAllowWhileIdle might work for Android 6 but not for Android 7. Idle mode is much more aggressive there and might even be engaged while the device is not stationary. During idle mode, the App will get access to the network every 1,2,4,6 hours only or when idle mode is disengaged.

[jpwsutton]

When forced into idle mode, this is the current behaviour:

07-25 14:13:37.769 5798-5898/paho.mqtt.java.example D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.ExampleAndroidClient1469452417189
07-25 14:13:37.770 5798-5898/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469452477770
07-25 14:13:37.770 5798-5898/paho.mqtt.java.example D/AlarmPingSender: Alarm scheule using setExact, delay: 60000
07-25 14:13:37.780 5798-5798/paho.mqtt.java.example I/System.out: LOG: Connected to: tcp://iot.eclipse.org:1883
07-25 14:13:37.907 5798-5798/paho.mqtt.java.example I/System.out: LOG: Subscribed!
07-25 14:13:38.012 5798-5900/paho.mqtt.java.example I/System.out: Message: exampleAndroidTopic : 3565
07-25 14:13:38.162 5798-5900/paho.mqtt.java.example I/System.out: Message: exampleAndroidTopic : 3565
07-25 14:15:08.371 5798-5898/paho.mqtt.java.example D/AlarmPingSender: Unregister alarmreceiver to MqttServiceExampleAndroidClient1469452417189
07-25 14:15:08.411 5798-5798/paho.mqtt.java.example I/System.out: LOG: The Connection was lost.

With the setExactAndAllowWhileIdle fix:

07-25 14:10:58.514 2585-2955/paho.mqtt.java.example D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.ExampleAndroidClient1469452257909
07-25 14:10:58.516 2585-2955/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469452318516
07-25 14:10:58.516 2585-2955/paho.mqtt.java.example D/AlarmPingSender: Alarm scheule using setExactAndAllowWhileIdle, delay: 60000
07-25 14:10:58.607 2585-2585/paho.mqtt.java.example I/System.out: LOG: Connected to: tcp://iot.eclipse.org:1883
07-25 14:11:02.143 2585-2585/paho.mqtt.java.example I/System.out: LOG: Subscribed!
07-25 14:11:02.151 2585-2957/paho.mqtt.java.example I/System.out: Message: exampleAndroidTopic : 3565
07-25 14:11:02.161 2585-2957/paho.mqtt.java.example I/System.out: Message: exampleAndroidTopic : 3565
07-25 14:11:58.520 2585-2585/paho.mqtt.java.example D/AlarmPingSender: Ping 1 times.
07-25 14:11:58.521 2585-2585/paho.mqtt.java.example D/AlarmPingSender: Check time :1469452318520
07-25 14:11:58.558 2585-2585/paho.mqtt.java.example D/AlarmPingSender: Schedule next alarm at 1469452378558
07-25 14:11:58.559 2585-2585/paho.mqtt.java.example D/AlarmPingSender: Alarm scheule using setExactAndAllowWhileIdle, delay: 60000
07-25 14:11:59.347 2585-2957/paho.mqtt.java.example D/AlarmPingSender: Success. Release lock(MqttService.client.ExampleAndroidClient1469452257909):1469452319347```

To test this simply, you can use this command to force the phone into idle mode: ./adb shell dumpsys deviceidle force-idle

@binarybucks, thanks for the heads up on this, where did you see it? I'm having trouble finding any info about setExactAndAllowWhileIdle in Android 7..

[binarybucks]

setExactAndAllowWhileIdle might work in 7 even when in idle mode, but establishing a network connection is a totally different thing. In addition, network connection change receivers behave weird as the corresponding intent is no longer fired to prevent wakeups.

[jpwsutton]

Thanks, I've found this article that gives more background on the changes: https://developer.android.com/preview/behavior-changes.html?utm_campaign=android_launch_developerpreview5_071816&utm_source=anddev&utm_medium=blog#perm

From this article, it looks like we might be an acceptable use case for being added to the whitelist: https://developer.android.com/training/monitoring-device-state/doze-standby.html#whitelisting-cases

The process of adding the app to a whitelist should probably not be in the Android service, but in the actual application though. If we do choose to go down this route, the instructions are here: https://developer.android.com/training/monitoring-device-state/doze-standby.html#support_for_other_use_cases

[jpwsutton]

Furthermore, using setExactAndAllowWhilstIdle will only allow the alarm to be called once every 9 minutes. So the Alarm will trigger once and then the connection will likely fail. https://plus.google.com/+JamesSutton42/posts/GQFy9QZEUqb

The Whitelist is starting to sound like our only option at this point..

[binarybucks]

Judging from some comments on Reddit and Medium, whitelisting also affects AppStandby (OS disabling network access to apps that haven't been used for some time or don't have a foreground service) but not Doze (OS disabling network access and stopping Alarms when the device is not charging).

Documentation is very spare on the possible impacts so we'll have to test this.

[jpwsutton]

It's looking more and more like there isn't much of a way around Doze. Here is what I've been able to gather:

• Doze is activated when the device is left unplugged, stationary, and with the screen turned off. Specific timings are up to OEMs, not google.
• When activated, Basic Alarms are deferred till maintenance windows which might be every 15 mins (Though I've seen reports that the time between windows increases after each window e.g. 15, 30, 60 mins...)
• Currently in Android 6, you can use setExactAndAllowWhilstIdle, however will only allow an alarm to be called every 9 minutes. So this workaround would require that keepalive is set to 9 minutes..
• setExactAndAllowWhilstIdle may not work in Android 7
• Applications can opt to be Whitelisted from doze on the device, either by triggering an permissions request or by the user manually adding them. Messaging Apps that can't use GCM seem to be an acceptable usecase for this: https://developer.android.com/training/monitoring-device-state/doze-standby.html#whitelisting-cases
• There are other task scheduling mechanisms in Android, but they are all affected by doze, and some of them would not allow network access which is a deal breaker for MQTT.

Because of these restrictions and from having a look at what other developers / projects have been doing to tackle doze I've got a few ideas that I'd like to put forward to the community:

• Create a Wiki page explaining what doze is, links to resources and suggestions about how developers using the Paho Android service can work around the restrictions.
• Add the setExactAndAllowWhilstIdle functionality into the AlarmPingSender class so that in Android 6 and above, developers wishing to have a keepalive of 9 minutes can do so if they wish.
• Add a check into the AlarmPingSender / connection loss code to identify when a connection has been lost due to Doze mode (i.e. How overdue was this alarm, if more than say.. 3 times the keepalive, assume the phone was in doze mode) when this occurs, add an additional message to the connection lost exception and maybe print a message to the log alerting any developers as to why the connection was lost with a link to the aforementioned wiki page.

I know that this solution isn't ideal, but after my discussion on the Android Google Plus community, it doesn't seem like there is any way to resolve this without causing some extra work for our developers. I definitely don't think that this service should be making any assumptions about how to run that could negatively affect the final apps e.g getting them banned from the google play store for abusing Whitelisting etc..

[binarybucks]

Doze is activated when the device is left unplugged, stationary, and with the screen turned off. Specific timings are up to OEMs, not google.

This is only true for Android 6. Starting with Android 7, doze is also activated when the device is not stationary

The workarounds sound reasonable. It might be a good idea to automatically try a reconnect during Doze maintenance intervals to dump buffered messages. I think there are broadcast intents sent when a maintenance interval occurs or Doze mode is exited.

[jpwsutton]

@binarybucks Good idea, I'll have a play and see if this can be added to the automatic reconnect behaviour. It might already just work as I believe that any deferred alarms will be called in the maintenance window, the connection would be lost and then assuming it was enabled, automatic reconnect should try and reconnect straight away. Whether this happens fast enough during a maintenance window and how long the service will have to complete it's work might be another question and could require some tweaks.

[binarybucks]

I'd be happy to test this. I'll have to investigate it anyway for #102

[kazixma]

Thankyou @jpwsutton and @binarybucks , What parameter to use with setExactAndAllowWhileIdle ? because I can not use parameter setExactAndAllowWhileIdle that same setExtract and set. What sample you use setExactAndAllowWhileIdle ? Thankyou

[binarybucks]

[https://developer.android.com/reference/android/app/AlarmManager.html#setExactAndAllowWhileIdle(int, long, android.app.PendingIntent)](https://developer.android.com/reference/android/app/AlarmManager.html#setExactAndAllowWhileIdle%28int, long, android.app.PendingIntent%29)

[ZhangXincun]

i have the same issue in android 4.4.2. sometimes it is ok

[qfly888]

`

<uses-permission android:name="android.permission.ACCESS_NETWORK_STATE" />

<uses-permission android:name="android.permission.CHANGE_NETWORK_STATE" />

<uses-permission android:name="android.permission.ACCESS_WIFI_STATE" />

<uses-permission android:name="android.permission.CHANGE_WIFI_STATE" />`