home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.56k stars 30.73k forks source link

Feeder Robot food level isn't in sync with the app #85159

Closed rccoleman closed 1 year ago

rccoleman commented 1 year ago

The problem

I added a Feeder Robot to my Whisker account yesterday and it was automatically pulled into my existing Whisker HA integration along with my 2 Litter Robots. Since then, I've noticed that the food level reported by the HA integration doesn't match what the app says. Right now, the app says that the feeder is 70% full, but the HA integration says that it's 90% full. I've tried power cycling the feeder, reloading the integration, and restarting HA, and it always stays with the incorrect 90% level. I haven't had the feeder long enough to know if it's really stuck or if the values will track with an offset, and I haven't spent time looking into the integration yet. I'll poke around, but I figured that it would be best to start with an issue.

I do have debug logging enabled for both pylitterbot and homeassistant.components.litterrobot, but while I see plenty of debug over the course of the day, mostly related to my Litterbots, the only logs related to the feeder are ones like this:

2023-01-04 11:50:33.035 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
2023-01-04 11:50:33.955 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection

What version of Home Assistant Core has the issue?

core-2023.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Litter Robot

Link to integration documentation on our website

https://www.home-assistant.io/integrations/litterrobot/

Diagnostics information

home-assistant_litterrobot_2023-01-04T23-20-55.873Z.log

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 1 year ago

Hey there @natekspencer, @tkdrob, mind taking a look at this issue as it has been labeled with an integration (litterrobot) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `litterrobot` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Change the title of the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign litterrobot` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


litterrobot documentation litterrobot source (message by IssueLinks)

rccoleman commented 1 year ago

Something is definitely weird here. When it dispensed a meal this morning, it dropped from 90% to 68% in the HA integration, while the iOS app was still reporting 70%. Now, after restarting HA for an unrelated reason, the HA integration is now back to reporting 90% full. I saw that the required package was doing some math to compute the food_level, and that may explain the 68% vs. 70% discrepancy, but the jump back to 90% following an HA restart is unexpected and incorrect.

natekspencer commented 1 year ago

The 90% to 68% drop is definitely weird and I would love to see any logs around that time. The other is not really a bug so much as a decision I made when implementing the food level property. The feeder currently reports a level between 0-9 and is mapped like so in the app (at least I project, I still haven't actually followed every level entry with the corresponding app value):

{9: 100, 8: 70, 7: 60, 6: 50, 5: 40, 4: 30, 3: 20, 2: 10, 1: 5, 0: 0}

However, when implementing it, I didn't have all of the data points nor time to sit through and try to capture all of them but knew the upper and lower limit, so used maths to round the percentage to the nearest 10% based on that 0-9 level. This is why you see 90% instead of 70% as my maths corresponds to the following map:

{9: 100, 8: 90, 7: 80, 6: 70, 5: 60, 4: 40, 3: 30, 2: 20, 1: 10, 0: 0}
natekspencer commented 1 year ago

The 68% is an anomaly as the formula int(round(self._state_info("level") / 9 * 100, -1)) should never be able to produce 68%.

rccoleman commented 1 year ago

Even with debug enabled, I really don't see much in the way of logging for the Feeder Robot. Here's everything from the last two HA starts:

rcoleman@rcoleman-linux /config % grep -i feederrobot *.log*
home-assistant.log:2023-01-05 14:13:47.039 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
home-assistant.log:2023-01-05 14:13:47.943 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection
home-assistant.log:2023-01-05 15:13:47.046 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
home-assistant.log:2023-01-05 15:13:48.333 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection
home-assistant.log:2023-01-05 16:13:48.053 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
home-assistant.log:2023-01-05 16:13:48.952 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection
home-assistant.log.1:2023-01-05 11:58:25.041 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
home-assistant.log.1:2023-01-05 11:58:25.943 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection
home-assistant.log.1:2023-01-05 12:58:25.040 DEBUG (MainThread) [pylitterbot.robot.feederrobot] Web socket monitor stopped
home-assistant.log.1:2023-01-05 12:58:25.977 DEBUG (MainThread) [pylitterbot.robot.feederrobot] restarted connection
rcoleman@rcoleman-linux /config % vi home-assistant.log.1   
rcoleman@rcoleman-linux /config % grep -i feeder-robot *.log*
home-assistant.log:2023-01-05 14:02:17.830 DEBUG (MainThread) [pylitterbot.robot] Feeder-Robot updated: {'iterable_item_added': {"root['feeding_meal'][0]": {'timestamp': '2023-01-05T22:02:16.93458+00:00', 'amount': 0.25, 'meal_name': 'Mid-afternoon', 'meal_number': 2, 'meal_total_portions': 1}}}
home-assistant.log:2023-01-05 15:27:19.763 DEBUG (MainThread) [pylitterbot.robot] Feeder-Robot updated: {'values_changed': {"root['state']['updated_at']": {'new_value': '2023-01-05T23:27:19.48185+00:00', 'old_value': '2023-01-05T20:24:52.1054+00:00'}}}
home-assistant.log.1:2023-01-05 12:24:52.411 DEBUG (MainThread) [pylitterbot.robot] Feeder-Robot updated: {'values_changed': {"root['state']['updated_at']": {'new_value': '2023-01-05T20:24:52.1054+00:00', 'old_value': '2023-01-05T18:53:34.250997+00:00'}}}

It also provided my afternoon snack and it's still reporting 90%, while the app is reporting 70%

natekspencer commented 1 year ago

It also provided my afternoon snack and it's still reporting 90%, while the app is reporting 70%

See my comment above about the conscious mapping decision I made

rccoleman commented 1 year ago

Got it, sorry for missing that. I'll see if I get some another unrounded result during feeding tomorrow, as I agree that it doesn't seem possible.

natekspencer commented 1 year ago

Thanks, I'm going to close this issue and you can create a new one if you see it happen again.

natekspencer commented 1 year ago

@home-assistant close