PingWorker not work

[shenyunhuan]

Work [ id=42e1814b-15be-45aa-9fba-293602b236b0, tags={ info.mqtt.android.service.ping.PingWorker } ] was cancelled java.util.concurrent.CancellationException: Task was cancelled. at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1184) at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:514) at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:475) at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:317) at androidx.work.impl.utils.SerialExecutorImpl$Task.run(SerialExecutorImpl.java:96) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637) at java.lang.Thread.run(Thread.java:1012)

[rainfoam]

@hannesa2 Changing the keepAlive time to a very short time such as 10 seconds will reproduce this problem very well. My solution is to modify "ExistingWorkPolicy. REPLACE" as "ExistingWorkPolicy. KEEP". I wonder if this is a good solution? Thanks!

[rainfoam]

log:

2023-09-19 10:54:24.775 16014-16315 ACLog D MQTT Ping AlarmPingSender start 2023-09-19 10:54:24.775 16014-16315 ACLog D MQTT Ping AlarmPingSender Schedule next alarm at 1695092074775 2023-09-19 10:54:34.791 16014-16244 ACLog D MQTT Ping PingWorker Sending at: 1695092074791 2023-09-19 10:54:34.791 16014-16244 ACLog D MQTT Ping AlarmPingSender Schedule next alarm at 1695092084791 2023-09-19 10:54:34.810 16014-16317 ACLog D MQTT Ping PingWorker Success. 2023-09-19 10:54:34.821 16014-16076 WM-WorkerWrapper I Work [ id=cfb5d49f-8685-45f9-acbe-c0a042abfea3, tags={ xx.xxx.common.mqtt.ping.PingWorker } ] was cancelled java.util.concurrent.CancellationException: Task was cancelled. at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1184) at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:514) at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:475) at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:311) at androidx.work.impl.utils.SerialExecutor$Task.run(SerialExecutor.java:91) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637) at java.lang.Thread.run(Thread.java:1012) 2023-09-19 10:54:44.806 16014-16244 ACLog D MQTT Ping PingWorker Sending at: 1695092084806 2023-09-19 10:54:44.807 16014-16244 ACLog D MQTT Ping AlarmPingSender Schedule next alarm at 1695092094807 2023-09-19 10:54:44.833 16014-16317 ACLog D MQTT Ping PingWorker Success. 2023-09-19 10:54:44.846 16014-16076 WM-WorkerWrapper I Work [ id=8542efe3-663a-40a2-872b-df4529f748a4, tags={ xx.xxx.common.mqtt.ping.PingWorker } ] was cancelled java.util.concurrent.CancellationException: Task was cancelled. at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1184) at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:514) at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:475) at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:311) at androidx.work.impl.utils.SerialExecutor$Task.run(SerialExecutor.java:91) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637) at java.lang.Thread.run(Thread.java:1012)

[hannesa2]

Please can you demonstrate your change as a pull request ?

Here you have something to read https://issuetracker.google.com/issues/122578012?pli=1

eg.

Status: Won't Fix (Intended Behavior) This is expected. You are calling: enqueueUniquePeriodicWork() with an ExistingPeriodicWorkPolicy.REPLACE. This will cancel running work, and kick off new instances of all Workers. https://github.com/rubensousa/WorkManagerKitkatBug/blob/master/app/src/main/java/com/github/rubensousa/workkitkatbug/MainActivity.kt#L24

I'm not sure if it's just a "(Intended Behavior"

[wwqbus]

since 4.1 i have noticed this as well but it makes it so that the connection has more losses then i had with 3.5.1

2023-09-29 09:06:22.148 28065-28106 WM-WorkerWrapper com.qbus.ubie I Work [ id=3e113b43-0d60-4a35-8d38-2e20860e8a54, tags={ info.mqtt.android.service.ping.PingWorker } ] was cancelled java.util.concurrent.CancellationException: Task was cancelled. at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1184) at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:514) at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:475) at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:317) at androidx.work.impl.utils.SerialExecutorImpl$Task.run(SerialExecutorImpl.java:96) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) at java.lang.Thread.run(Thread.java:923) 2023-09-29 09:06:40.685 28065-28079 com.qbus.ubie com.qbus.ubie I Background concurrent copying GC freed 80343(6260KB) AllocSpace objects, 0(0B) LOS objects, 46% free, 6950KB/12MB, paused 159us total 113.095ms 2023-09-29 09:06:48.205 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE? 2023-09-29 09:06:48.491 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE:UB10000005EE:192.168.75.120:255.255.255.0:192.168.75.1:192.168.75.3:3000 2023-09-29 09:06:48.808 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE:PROTO0000009:192.168.75.110:255.255.255.0:192.168.75.1:192.168.75.3:3000 2023-09-29 09:06:57.704 28065-28079 com.qbus.ubie com.qbus.ubie I Background young concurrent copying GC freed 72797(5959KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 7161KB/12MB, paused 5.371ms total 52.301ms 2023-09-29 09:07:18.205 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE? 2023-09-29 09:07:18.497 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE:UB10000005EE:192.168.75.120:255.255.255.0:192.168.75.1:192.168.75.3:3000 2023-09-29 09:07:18.802 28065-28662 ContentValues com.qbus.ubie I reveived packet: UBIE:PROTO0000009:192.168.75.110:255.255.255.0:192.168.75.1:192.168.75.3:3000 2023-09-29 09:07:22.796 28065-20168 mqtt com.qbus.ubie E connection lost cloud Connection lost (32109) - java.io.EOFException at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) at java.lang.Thread.run(Thread.java:923) Caused by: java.io.EOFException at java.io.DataInputStream.readByte(DataInputStream.java:270) at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) at java.lang.Thread.run(Thread.java:923)  2023-09-29 09:07:22.964 28065-28665 WM-Processor com.qbus.ubie W Didn't find WorkSpec for id WorkGenerationalId(workSpecId=263da75c-44d6-4b8a-b408-5a08fa7a3557, generation=0) 2023-09-29 09:07:23.802 28065-20307 System.out com.qbus.ubie I [socket]:check permission begin! 2023-09-29 09:07:24.301 28065-20014 mqtt com.qbus.ubie I connected to mqtt, was reconnect: true

[uiTravis]

It's a bug for PingWorker. comment There's no any ping history in the broker's log.

[SM2A]

I was testing the latest version and still facing this issue. As a sample I just ran basicSample and waited for a while. In the logcat you can constantly see mentioned errors.

[GCIotron]

Hello, I'm having the same issue using version 4.0 on Samsung XCover with Android 13

[don-pironet-hatch]

Hi, we are having the same issue on version 4.2.4 on Samsung Galaxy tab with Android 11 and on a Pixel 6A with Android 14.