wallpanel-android icon indicating copy to clipboard operation
wallpanel-android copied to clipboard

[BUG] Endless loop MQTT battery sensor publish

Open FredericMa opened this issue 2 years ago • 6 comments

Describe the bug Since last week I updated to the latest version of WallPanel since I was still using the last version of the ThanksMister repo. Since then I noticed that sometimes there was a significant increase of traffic on the MQTT broker. See screenshot below: image

It happened again this morning so I subscribed to the root topic with the wildcard character. Apparently there was a massive amount of messages being published on the sensor/battery topic. It generated about 24.000 messages in about 3 minutes.

Even now the battery state is published twice every minute: image

To Reproduce No clear scenario to reproduce. I don't know what could trigger it since it started mostly during the night. The screen is turned off during the night via an automation. I don't know if that could cause that behavior.

This behavior has never been observed with the previous versions of WallPanel I've used.

Smartphone (please complete the following information):

  • Device: Lenovo TB-X304F
  • OS: Android 10
  • Application version v0.10.0 Build 1

FredericMa avatar Aug 28 '22 21:08 FredericMa

It happened again this morning. Now I managed to take screenshot of the messages on the broker: image When I terminate the app the flood of messages also stops.

FredericMa avatar Aug 29 '22 06:08 FredericMa

Have you looked in the settings on how often the sensors should be updated? The battery readings are only sent in a set timer so it kind of looks like that the sensor settings are set to (close to) 0ms.

Also since it happens when the screen is off, do you have the option to check if the app suddenly restarts all the time overnight?

TheTimeWalker avatar Aug 29 '22 09:08 TheTimeWalker

Thanks for your reply.

I used the same settings as the latets version of ThanksMister and it is set to 60 seconds.

It starts most of the time during the night but the app isn't restarting since this morning it was sending flood of messages when I took the screenshot and app was running fine (from the UI point of view).

Is it possible that additional timers are being created over time but sometimes not get canceled?

FredericMa avatar Aug 29 '22 09:08 FredericMa

Is there anything I can do to get this issue forward?

FredericMa avatar Sep 01 '22 16:09 FredericMa

Sorry, I'm a bit stumped on this as well as I can't reproduce this personally :(

Is it only the battery state that gets pushed endlessly or do you have other messages sent as well?

TheTimeWalker avatar Sep 01 '22 21:09 TheTimeWalker

Yes, it is only the battery state but the tablet also doesn't have any other supported sensors. The regular state with the current url, screenon, ... is only reported once every minute. If I restart the app I notice that the battery state is always reported twice every minute with one millisecond in between. But for some reason it runs out of hand sometimes with this massive amount of publishes. It didn't had the issue for the last 24h.

HA also sends a few commands to the tablet; at midnight it restarts the app (since I noticed the app slowing down if it remained running for several days) and it controls the brightness and the screen on/off. I don't know if this could be related.

Is there any way to debug the app or to see logs on the tablet?

FredericMa avatar Sep 02 '22 20:09 FredericMa

I also have this issue if the connection to the MQTT broker is lost / restored. I am using mosquitto as broker and after I restart mosquitto, the Wallpanel app starts spamming MQTT messages.

h44z avatar Sep 19 '22 15:09 h44z

I have this same issue using Mosquitto Broker with Home assistant.

After restarting everything, all seems fine at first, but after some times, more and more messages from battery level are send at roughly the same second.

Components used:

  • Mosquitto Broker v6.1.3
  • Wall Panel v0.10.0 Build 1

Configuration of WallPanel:

  • Camera : enabled
  • MQTT discovery : disabled
  • Sensor publishing : enabled
  • Publish frequency : 60
  • Sensor list : Battery level, USB plugged, AC plugged, Charging

Example with the extract from MQTT logs of HA : image

Clement-B avatar Sep 24 '22 23:09 Clement-B

I reverted back to the latest version of ThanksMister but it looks like it suffers the same issue. So the issue was already present before upgrading to your latest build. I switched over to EMQX last weekend so now you can see the increase in messages during the night: image

A part of the log (milliseconds weren't logged):

2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}
2022-09-28T09:24:07+00:00 [PUBLISH] [email protected]:38273 msg: publish_to, topic: wallpanel/sensor/battery, payload: {"value":77,"unit":"%","charging":true,"acPlugged":false,"usbPlugged":false}

FredericMa avatar Sep 28 '22 09:09 FredericMa

At the bottom there is a full log that's from the point where I turned off the screen. You can see that there are disconnects which might be related to battery optimization of Android so disabling that for the app might solve it for me but nonetheless there are also use cases this can happen while the screen remains on like broker restart, network disruption, ... So this is an issue that should be fixed. The number of published messages grows over time. It looks like there are multiple connections active to the broker at the same time. Like you can see here (port 49105 and 49106 for example):

2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49103 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: 1], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [UNSUBSCRIBE] [email protected]:49102 msg: unsubscribe, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: wallpanel], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49104 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: 1], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [UNSUBSCRIBE] [email protected]:49103 msg: unsubscribe, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: wallpanel], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49105 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: 1], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [UNSUBSCRIBE] [email protected]:49104 msg: unsubscribe, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: wallpanel], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49106 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: 1], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [UNSUBSCRIBE] [email protected]:49105 msg: unsubscribe, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: wallpanel], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49106 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 1], subid: 1], topic: wallpanel/command
2022-09-29T16:11:50+00:00 [SUBSCRIBE] [email protected]:49106 msg: subscribe, sub_id: wallpanel, sub_opts: [nl: 0, qos: 2, rap: 0, rh: 0, sub_props: [Subscription-Identifier: 2], subid: 2], topic: wallpanel/command

[email protected]_WallpanelLog_2022-09-29.log

FredericMa avatar Sep 29 '22 18:09 FredericMa

I also have another strange behavior and I dont know if t's related.

When sometimes I try to disable camera using mqtt, wall panel suddently close off MQTT connection and become offline. I got no sensor publishing anymore. It become online again after a long time or the day after when a full restart has been done during the night.

@FredericMa Would you say your PR #33 could fix this kind of issue as well ? I see that you did a fix about reconnect logic.

Clement-B avatar Oct 05 '22 13:10 Clement-B

I'd suggest creating a new issue for that so we can keep that in track. It could be an unrelated issue as it doesn't sound like it's in an endless state

TheTimeWalker avatar Oct 05 '22 14:10 TheTimeWalker

@FredericMa Would you say your PR #33 could fix this kind of issue as well ? I see that you did a fix about reconnect logic.

It might fix it since I also fixed a few things in the reconnect logic. If you can easily reproduce it I would give it a try once the PR is merged and a new release is available.

FredericMa avatar Oct 05 '22 15:10 FredericMa