sh00t2kill
Robot will vacuum multiple times a day
I noticed that when the integration is enabled, my vacuum will vacuum multiple times a day at random times (I don't have any automation scheduled, and the app does not support scheduling on my model).
Device model: DOLPHIN E35i EU CB
@elad-bar @sh00t2kill what data can I send to help debug this problem?
Thanks
I have noticed this too, just today.
@oNaiPs does it stop if you restart HA ?
@sh00t2kill I tried restarting the integration but still seems to happen. It will only stop if the integration is completely disabled.
Mine is still doing it. I can't see anything in the debug log explicitly telling it to clean.
With the history log of the component, can you check what triggered it and share it here?
I just had this happen again last night and today (started a few minutes ago), I'm using 1.0.1.
Look at the video below for the log book. Def something strange as some sensors states seems to be changing too many times. Also, it does not state what was the reason for the cleaning to start. https://youtu.be/5vWqxWLh6fc
I did try an automation earlier today and it showed this log.
Looks to me like something in the code logic (a reconnect to aws or something) could be triggering the cleaning cycle.
That's super weird, maybe your robot developed personality 🤔, Can you please enable debug logs so next time it will happen? So i will be able to understand the sequence of events led to it, it didn't happen to me once but even if it would of happen I would notice it... I see that your robot is E35i, right?
According to the video, it seems that something is very unstable, @sh00t2kill does it happen also for you?
For my robot there are much less disconnections, I would like yo check why robot type constantly changes between value to unknown, I do see it in my robot from time to time, maybe that has something with it
@oNaiPs you screenshot are really indicating that something triggered it, without debug level logs I cannot investigate it,
I'm looking for a message starts with Published message: at the time it happens, it is the only place in code that sends command to the robot, so I would like to trace it back to what originated it, clearly it's not an automation,
it's either from the code or from the mobile app.
thanks
@elad-bar @sh00t2kill here goes a debug log. You will find two instances of it cleaning by itself (the first one I canceled manually).
https://www.dropbox.com/scl/fi/8i65lq6ccg1hn171wcquu/home-assistant_dolphin_2023-07-27T08-26-02.206Z.log?rlkey=bconkq96jwsx6ymd0msdu8o6r&dl=1
Security note: I noted that access/refresh/etc tokens are being printed in the logs. We should obfuscate those to prevent people leaking auth when sending logs over the internet.
Logs contains everything needed to debug, I stringly suggest not to dump all logs here but to share them privately, unless it is focused set of messages... info messages should not invlude sensitive data
As @elad-bar said only when debug is turned on.
FWIW mine stopped. No idea what happened.
By any chance did you attempt to start a cleaning run and the robot was off-line and didn't respond?
That's what I think triggered it in my case.
I see in logs that it was triggered by the service for regular cleaning cycle, the I see another cycle that was triggered without being asked to, only difference between 2 cycles, a message was sent with the following details:
2023-07-26 18:31:04.701 DEBUG (Thread-3868 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"systemState":{"AppID":4},"robotSerial":"I5688KMR2N"}},"metadata":{"reported":{"systemState":{"AppID":{"timestamp":1690392664}},"robotSerial":{"timestamp":1690392664}}},"version":59,"timestamp":1690392664}
if you will look at the code, you will find out that it's not available over there, my assumption is that the mobile app is trying to reconnect and sends that message following:
2023-07-26 18:31:07.107 DEBUG (Thread-3868 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"systemState":{"pwsState":"on","robotState":"init","robotType":"
less than 3 seconds afterward the robot starts working, any time near that incident, none of operating requests are being sent but get status which happens many times before without triggering it, have you tried to suspend the mobile app / remove it from the mobile phone? only indication for that appid in MyDolphin code is related to appid, is in context of firebase, which triggers that event
I would like yo check why robot type constantly changes between value to unknown,
@elad-bar @sh00t2kill I've been digging a bit through the codebase, and found the reason why there is a lot of triggers between a value and unknown. Check the following stream of messages:
2023-08-14 20:09:56.804 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:56.811 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:56.815 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:56.815 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"systemState":{"pwsState":"off","robotState":"notConnected","robotType":"S2","isBusy":false,"rTurnOnCount":118,"timeZone":60},"debug":{"systemTime":1692043776,"dynamicFlg":2,"weeklyNextOp":0,"automationMode":1,"WIFI_RSSI":-83,"dataUploadNumber":0,"updateTime":{"hour":2,"min":0},"resetSource":96,"bleMacAddress":"00:00:00:00:00:00","wifiMacAddress":"00:00:00:00:00:00","rtcFlag":true,"disconnectionTrigger":{"code":12,"timeStamp":1692043776}},"filterBagIndication":{"state":102,"resetFBI":false},"cycleInfo":{"cleaningMode":{"mode":"all","cycleTime":120},"cycleStartTime":1692024576,"cycleStartTimeUTC":1692020992}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040196}},"systemState":{"pwsState":{"timestamp":1692040196},"robotState":{"timestamp":1692040196},"robotType":{"timestamp":1692040196},"isBusy":{"timestamp":1692040196},"rTurnOnCount":{"timestamp":1692040196},"timeZone":{"timestamp":1692040196}},"debug":{"systemTime":{"timestamp":1692040196},"dynamicFlg":{"timestamp":1692040196},"weeklyNextOp":{"timestamp":1692040196},"automationMode":{"timestamp":1692040196},"WIFI_RSSI":{"timestamp":1692040196},"dataUploadNumber":{"timestamp":1692040196},"updateTime":{"hour":{"timestamp":1692040196},"min":{"timestamp":1692040196}},"resetSource":{"timestamp":1692040196},"bleMacAddress":{"timestamp":1692040196},"wifiMacAddress":{"timestamp":1692040196},"rtcFlag":{"timestamp":1692040196},"disconnectionTrigger":{"code":{"timestamp":1692040196},"timeStamp":{"timestamp":1692040196}}},"filterBagIndication":{"state":{"timestamp":1692040196},"resetFBI":{"timestamp":1692040196}},"cycleInfo":{"cleaningMode":{"mode":{"timestamp":1692040196},"cycleTime":{"timestamp":1692040196}},"cycleStartTime":{"timestamp":1692040196},"cycleStartTimeUTC":{"timestamp":1692040196}}}},"version":139191,"timestamp":1692040196}
2023-08-14 20:09:57.196 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:57.208 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:57.209 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:57.209 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"nextCycleInfo":{"cleaningMode":{"mode":"all"},"nextCycleDuration":120}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040197}},"nextCycleInfo":{"cleaningMode":{"mode":{"timestamp":1692040197}},"nextCycleDuration":{"timestamp":1692040197}}}},"version":139192,"timestamp":1692040197}
2023-08-14 20:09:57.520 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:57.555 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:57.556 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:57.557 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"robotError":{"errorCode":0,"pcbHours":0,"pcbMin":0,"turnOnCount":0,"faultValue1":0}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040197}},"robotError":{"errorCode":{"timestamp":1692040197},"pcbHours":{"timestamp":1692040197},"pcbMin":{"timestamp":1692040197},"turnOnCount":{"timestamp":1692040197},"faultValue1":{"timestamp":1692040197}}}},"version":139193,"timestamp":1692040197}
2023-08-14 20:09:57.810 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:57.832 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:57.841 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:57.841 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"pwsError":{"errorCode":255,"pcbHours":65535,"pcbMin":255,"turnOnCount":65535,"holdCount":0,"faultValue1":65535,"faultValue2":65535}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040197}},"pwsError":{"errorCode":{"timestamp":1692040197},"pcbHours":{"timestamp":1692040197},"pcbMin":{"timestamp":1692040197},"turnOnCount":{"timestamp":1692040197},"holdCount":{"timestamp":1692040197},"faultValue1":{"timestamp":1692040197},"faultValue2":{"timestamp":1692040197}}}},"version":139194,"timestamp":1692040197}
2023-08-14 20:09:58.129 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:58.130 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:58.130 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"navMode":{"isSmart":false},"cycleInfo":{"cleaningMode":{"mode":"all","cycleTime":120},"cycleStartTime":1692024576,"cycleStartTimeUTC":1692020992}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040198}},"navMode":{"isSmart":{"timestamp":1692040198}},"cycleInfo":{"cleaningMode":{"mode":{"timestamp":1692040198},"cycleTime":{"timestamp":1692040198}},"cycleStartTime":{"timestamp":1692040198},"cycleStartTimeUTC":{"timestamp":1692040198}}}},"version":139195,"timestamp":1692040198}
2023-08-14 20:09:58.145 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:58.399 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:58.406 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:58.406 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"cleaningModes":{"all":120,"short":60,"cove":120,"floor":120,"water":120,"ultra":120,"spot":120,"wall":120,"ticTac":120,"custom":120,"pickup":12}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040198}},"cleaningModes":{"all":{"timestamp":1692040198},"short":{"timestamp":1692040198},"cove":{"timestamp":1692040198},"floor":{"timestamp":1692040198},"water":{"timestamp":1692040198},"ultra":{"timestamp":1692040198},"spot":{"timestamp":1692040198},"wall":{"timestamp":1692040198},"ticTac":{"timestamp":1692040198},"custom":{"timestamp":1692040198},"pickup":{"timestamp":1692040198}}}},"version":139196,"timestamp":1692040198}
2023-08-14 20:09:58.410 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:58.696 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:58.710 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:58.713 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:58.713 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"led":{"ledEnable":true,"ledIntensity":100,"ledMode":1}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040198}},"led":{"ledEnable":{"timestamp":1692040198},"ledIntensity":{"timestamp":1692040198},"ledMode":{"timestamp":1692040198}}}},"version":139197,"timestamp":1692040198}
2023-08-14 20:09:58.891 ERROR (SyncWorker_8) [pymodbus.logging] Connection to (192.168.0.133, 8899) failed: timed out
2023-08-14 20:09:58.951 ERROR (SyncWorker_2) [pymodbus.logging] Connection to (192.168.0.133, 8899) failed: [Errno 113] Host is unreachable
2023-08-14 20:09:58.999 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:59.008 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:59.010 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:59.010 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"weeklySettings":{"isInRepeatMode":false,"triggeredBy":0}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040198}},"weeklySettings":{"isInRepeatMode":{"timestamp":1692040198},"triggeredBy":{"timestamp":1692040198}}}},"version":139198,"timestamp":1692040198}
2023-08-14 20:09:59.297 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update
2023-08-14 20:09:59.311 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/documents
2023-08-14 20:09:59.316 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Message received for device I5688KMR2N, Topic: $aws/things/I5688KMR/shadow/update/accepted
2023-08-14 20:09:59.316 DEBUG (Thread-16 (_dispatch)) [custom_components.mydolphin_plus.managers.aws_client] Payload: {"state":{"reported":{"isConnected":{"connected":true},"systemState":{"pwsState":"off","robotState":"notConnected"},"weeklySettings":{"sunday":{"isEnabled":false,"time":{"hours":255,"minutes":255},"cleaningMode":{"mode":"all"}},"triggeredBy":0,"isInRepeatMode":false}}},"metadata":{"reported":{"isConnected":{"connected":{"timestamp":1692040199}},"systemState":{"pwsState":{"timestamp":1692040199},"robotState":{"timestamp":1692040199}},"weeklySettings":{"sunday":{"isEnabled":{"timestamp":1692040199},"time":{"hours":{"timestamp":1692040199},"minutes":{"timestamp":1692040199}},"cleaningMode":{"mode":{"timestamp":1692040199}}},"triggeredBy":{"timestamp":1692040199},"isInRepeatMode":{"timestamp":1692040199}}}},"version":139199,"timestamp":1692040199}
You will notice that the first message will have the robotType defined on systemState, but at the last message, that does not get reported, and the logic here will remove the value.
This is making the reported value constaly changing (see screenshot)
It is also making the system status constantly being re-evaluated since robot type is used in the comparison. I'm not yet sure if this is what is causing the problems from above, but its definitely not intended behavior.
Can you help fix this? Happy to test a patch with an attempt fix.
I need to apply code fix for it, but that's not the issue, as it doesn't send request upon that information just updates the component, I have it also and I didn't see a single time that the robot started working on its own after restart but when I had some connectivity issues with the mobile app, after stop using the mobile app, problem gone... thanks for reminding that issue, will release a fix for it soon
Thanks @elad-bar!
I setup a local HA development environment only with this custom component to see if I can debug this further. Will let you know of other findings.
You can just set the component log level in configuration.yaml to debug it will log it since the moment ha is starting up
I see the same symptoms robot starts cleaning multiple times a day, the cleaning mode is also set to regular in stead of floor only what we usually run. Dont know if it is the same issue.
home-assistant_2024-01-15T07-13-32.487Z.log Is this what you need, I am new to HA so I am still in the learning curve sorry for that
@Jeroen-73 according to the logs you have provided, no action was reported not executed by the intergation, i think that log is not in debug level and contain lots of other components.
can you please provide log with debug level enabled?
thanks
I see you closed this thread just 5 hours ago. Coincidentally I just started looking for this issue because mine started showing this behaviour again since a few days, while in the past months it hasn't happened at all. It just started one cycle two hours ago on its own... Did you update anything in the integration recently?
From the very begining there was 0 indication that integration cause it, all logs showed that it's being triggered from something happens outside the integration and just notifing the integration it was started, Since it was stated it is not happening i closed that issue, If you find anything we will reopen this issue