PingWorker not work #502

shenyunhuan · 2023-08-17T02:43:30Z

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 · 2023-09-19T02:52:05Z

@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 · 2023-09-19T02:55:21Z

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 · 2023-09-19T04:13:50Z

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 · 2023-09-29T07:09:03Z

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 · 2024-01-10T06:51:24Z

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

SM2A · 2024-03-25T09:48:05Z

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 · 2024-03-28T09:23:28Z

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

don-pironet-hatch · 2024-04-26T12:34:25Z

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.

contigo · 2024-08-12T09:38:15Z

hello
android 12(LG V50), 14 (Galaxy Z Fold3 5G) and lib 3.6.4 same issue
any solution?

hannesa2 · 2024-08-12T10:25:44Z

same issue

This is too easy.

which version do you use ?
How does your issue looks like ?

contigo · 2024-08-13T02:00:38Z

same issue

This is too easy.

which version do you use ?

I use version 3.6.4

How does your issue looks like ?

I checked that the operation was canceled in the background task inspector of the app inspector in Android Studio. It is not 100% an error.

hannesa2 · 2024-08-14T12:48:18Z

Cancellation does not mean that it's automatic an error. It's a cancel !

Btw, please consider to move to
https://github.com/hannesa2/paho.mqtt.android/releases/tag/4.2.4
I personally would use
https://github.com/hannesa2/paho.mqtt.android/releases/tag/4.3.beta5

craigt543nz · 2024-10-19T23:48:30Z

I have the same issue on multiple test devices (new and old). I'm currently testing on a Galaxy S10, Android version 12 and MQTT version 4.2.4. Error message below. Any progress with this issue?

BTW, great work supporting this library.

12:39:07.323 I Work [ id=8beff531-e410-4953-8d28-d189953300fc, tags={ info.mqtt.android.service.ping.PingWorker } ] was cancelled
java.util.concurrent.CancellationException: Task was cancelled.
at T0.g.f(Unknown Source:32)
at T0.g.get(SourceFile:86)
at l.k.f(Unknown Source:9)

chrjsorg · 2024-11-29T06:50:25Z

The issue is still present in 4.3.beta5. Without any interaction. Just opened a connection and did a subscribe.

2024-11-29 07:48:54.369 10458-10458 WM-WorkerWrapper         D  Starting work for info.mqtt.android.service.ping.PingWorker
2024-11-29 07:48:54.373 10458-10529 PingWorker               D  Sending Ping at: 2024-11-29 07:48:54Z
2024-11-29 07:48:54.376 10458-10529 AlarmPingSender          D  Schedule next alarm at 2024-11-29 07:49:04Z
2024-11-29 07:48:54.387 10458-10542 WM-Processor             D  Processor cancelling 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e
2024-11-29 07:48:54.393 10458-10542 WM-Processor             D  WorkerWrapper interrupted for 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e
2024-11-29 07:48:54.400 10458-10542 WM-GreedyScheduler       D  Cancelling work ID 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e
2024-11-29 07:48:54.420 10458-10542 WM-SystemJobScheduler    D  Scheduling work ID 792c6da1-ab12-4ae0-adae-c0f6f25b71ebJob ID 175
2024-11-29 07:48:54.427 10458-10542 WM-WorkerWrapper         I  Work [ id=40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e, tags={ info.mqtt.android.service.ping.PingWorker } ] was cancelled (Ask Gemini)
                                                                androidx.work.impl.WorkerStoppedException
                                                                	at androidx.work.impl.WorkerWrapper.interrupt(WorkerWrapper.kt:348)
                                                                	at androidx.work.impl.Processor.interrupt(Processor.java:439)
                                                                	at androidx.work.impl.Processor.stopAndCancelWork(Processor.java:280)
                                                                	at androidx.work.impl.utils.CancelWorkRunnable.cancel(CancelWorkRunnable.kt:33)
                                                                	at androidx.work.impl.utils.CancelWorkRunnable.forNameInline$lambda$0(CancelWorkRunnable.kt:127)
                                                                	at androidx.work.impl.utils.CancelWorkRunnable.$r8$lambda$gmz-7SyxTGDd6CwHjvOsJ11-hcc(Unknown Source:0)
                                                                	at androidx.work.impl.utils.CancelWorkRunnable$$ExternalSyntheticLambda0.run(D8$$SyntheticClass:0)
                                                                	at androidx.room.RoomDatabase.runInTransaction(RoomDatabase.kt:585)
                                                                	at androidx.work.impl.utils.CancelWorkRunnable.forNameInline(CancelWorkRunnable.kt:123)
                                                                	at androidx.work.impl.utils.EnqueueRunnable.enqueueWorkWithPrerequisites(EnqueueRunnable.java:249)
                                                                	at androidx.work.impl.utils.EnqueueRunnable.enqueueContinuation(EnqueueRunnable.java:136)
                                                                	at androidx.work.impl.utils.EnqueueRunnable.processContinuation(EnqueueRunnable.java:129)
                                                                	at androidx.work.impl.utils.EnqueueRunnable.addToDatabase(EnqueueRunnable.java:93)
                                                                	at androidx.work.impl.utils.EnqueueRunnable.enqueue(EnqueueRunnable.java:74)
                                                                	at androidx.work.impl.WorkContinuationImpl.lambda$enqueue$0$androidx-work-impl-WorkContinuationImpl(WorkContinuationImpl.java:201)
                                                                	at androidx.work.impl.WorkContinuationImpl$$ExternalSyntheticLambda0.invoke(D8$$SyntheticClass:0)
                                                                	at androidx.work.OperationKt.launchOperation$lambda$2$lambda$1(Operation.kt:50)
                                                                	at androidx.work.OperationKt.$r8$lambda$XKAkIiEN7OgIvwuLUZRQpJhjmyE(Unknown Source:0)
                                                                	at androidx.work.OperationKt$$ExternalSyntheticLambda1.run(D8$$SyntheticClass:0)
                                                                	at androidx.work.impl.utils.SerialExecutorImpl$Task.run(SerialExecutorImpl.java:96)
                                                                	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                	at java.lang.Thread.run(Thread.java:1012)
2024-11-29 07:48:54.429 10458-10542 WM-WorkerWrapper         D  Status for 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e is null ; not doing any work
2024-11-29 07:48:54.430 10458-10542 WM-StopWorkRunnable      D  StopWorkRunnable for 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e; Processor.stopWork = false
2024-11-29 07:48:54.431 10458-10458 WM-Processor             D  Processor 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e executed; reschedule = false
2024-11-29 07:48:54.434 10458-10550 WM-GreedyScheduler       D  Cancelling work ID 40669dfb-b0cf-4f14-8c9c-2aeadc2ccb4e
2024-11-29 07:48:54.553 10458-10570 PingWorker$doWork        D  Success null

I cannot currently see that it is causing any problems in use. It just floods the logs.

Cheers & thanks for this fork.

hannesa2 added the A sample is required label Aug 17, 2023

SM2A mentioned this issue Jan 17, 2024

API Level 34 on Version 3.5.3 #548

Closed

hannesa2 mentioned this issue Nov 25, 2024

MQTT连接后androidx.work mqtt的消息也收不到 #664

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PingWorker not work #502

PingWorker not work #502

shenyunhuan commented Aug 17, 2023

rainfoam commented Sep 19, 2023

rainfoam commented Sep 19, 2023 •

edited

Loading

hannesa2 commented Sep 19, 2023

wwqbus commented Sep 29, 2023

uiTravis commented Jan 10, 2024 •

edited

Loading

SM2A commented Mar 25, 2024

GCIotron commented Mar 28, 2024 •

edited

Loading

don-pironet-hatch commented Apr 26, 2024

contigo commented Aug 12, 2024

hannesa2 commented Aug 12, 2024

contigo commented Aug 13, 2024

hannesa2 commented Aug 14, 2024 •

edited

Loading

craigt543nz commented Oct 19, 2024

chrjsorg commented Nov 29, 2024

PingWorker not work #502

PingWorker not work #502

Comments

shenyunhuan commented Aug 17, 2023

rainfoam commented Sep 19, 2023

rainfoam commented Sep 19, 2023 • edited Loading

hannesa2 commented Sep 19, 2023

wwqbus commented Sep 29, 2023

uiTravis commented Jan 10, 2024 • edited Loading

SM2A commented Mar 25, 2024

GCIotron commented Mar 28, 2024 • edited Loading

don-pironet-hatch commented Apr 26, 2024

contigo commented Aug 12, 2024

hannesa2 commented Aug 12, 2024

contigo commented Aug 13, 2024

hannesa2 commented Aug 14, 2024 • edited Loading

craigt543nz commented Oct 19, 2024

chrjsorg commented Nov 29, 2024

rainfoam commented Sep 19, 2023 •

edited

Loading

uiTravis commented Jan 10, 2024 •

edited

Loading

GCIotron commented Mar 28, 2024 •

edited

Loading

hannesa2 commented Aug 14, 2024 •

edited

Loading