search

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
71.11k stars 29.79k forks source link

ZHA Metering channel value formatting (Fail after some restarts) #37048

Closed hellcry37 closed 4 years ago

hellcry37 commented 4 years ago

The problem

The issue that I have is simple, sometimes when i restart Home Assistant the metric is exactly like it was here #36697 Basically it will show to me a consumption of 44W instead of 4.4W

Environment

arch x86_64
dev false
docker true
hassio false
installation_type Home Assistant Container
os_name Linux
os_version 5.4.0-37-generic
python_version 3.7.7
timezone Europe/Bucharest
version 0.111.4
virtualenv false

Problem-relevant configuration.yaml

integration via UI

Traceback/Error logs

nothing here

Additional information

To fix this issue I have to restart Home Assistant one more time. This happens random, no errors of any kind in Home Assistant logs.

Used devices: Zigbee controller: ConBee II Zigbee device: Heiman Zigbee Power Metering Plug HS2SK-E-EU

probot-home-assistant[bot] commented 4 years ago

Hey there @dmulcahey, @adminiuga, mind taking a look at this issue as its been labeled with an integration (zha) you are listed as a codeowner for? Thanks! (message by CodeOwnersMention)

Adminiuga commented 4 years ago

Can you post Zigbee signature of the device with the issue? Config panel -> device -> Zigbee signature

hellcry37 commented 4 years ago

want to help, but can't find it, can you be more specific please?

I don't have this path: Config panel -> device -> Zigbee signature

I do have: Configuration -> Devices -> List of all devices (could not find any zigbee signature) Configuration -> Zigbee Home Automation -> list of all zigbee devices i have (could not find any zigbee signature)

hellcry37 commented 4 years ago

I observed that from 2 x Heiman Zigbee Power Metering Plug HS2SK-E-EU only one has this issue: TV and AC are both using same type of plug, as you can see in image one works ok (TV) and one not (AC) after restarting

https://ibb.co/FW3kVjV

Adminiuga commented 4 years ago

doh, yep, it should be Config Panel -> ZHA -> pick your device from the drop down -> Zigbee signature

The url is not opening. Can you just post it here between tripple backticks -- ```

hellcry37 commented 4 years ago

url with the image:

https://ibb.co/FW3kVjV

url with what i see when i open the device in question:

https://ibb.co/ZSyZJ6R
Adminiuga commented 4 years ago

from https://ibb.co/ZSyZJ6R need the output of "zigbee information"

hellcry37 commented 4 years ago

The device with issue:

{
  "node_descriptor": "<NodeDescriptor byte1=1 byte2=64 mac_capability_flags=142 manufacturer_code=4619 maximum_buffer_size=82 maximum_incoming_transfer_size=82 server_mask=10752 maximum_outgoing_transfer_size=82 descriptor_capability_field=0>",
  "endpoints": {
    "1": {
      "profile_id": 260,
      "device_type": "0x0051",
      "in_clusters": [
        "0x0000",
        "0x0003",
        "0x0004",
        "0x0006",
        "0x0009",
        "0x0702",
        "0x0b04"
      ],
      "out_clusters": [
        "0x0003",
        "0x0019"
      ]
    }
  },
  "manufacturer": "Heiman",
  "model": "SmartPlug",
  "class": "zigpy.device.Device"
}

the device that works ok

{
  "node_descriptor": "<NodeDescriptor byte1=1 byte2=64 mac_capability_flags=142 manufacturer_code=4619 maximum_buffer_size=82 maximum_incoming_transfer_size=82 server_mask=10752 maximum_outgoing_transfer_size=82 descriptor_capability_field=0>",
  "endpoints": {
    "1": {
      "profile_id": 260,
      "device_type": "0x0051",
      "in_clusters": [
        "0x0000",
        "0x0003",
        "0x0004",
        "0x0006",
        "0x0009",
        "0x0702",
        "0x0b04"
      ],
      "out_clusters": [
        "0x0003",
        "0x0019"
      ]
    }
  },
  "manufacturer": "Heiman",
  "model": "SmartPlug",
  "class": "zigpy.device.Device"
}

From what I see nothing is different.

Adminiuga commented 4 years ago

Would you be able to try changes in https://github.com/Adminiuga/home-assistant/commit/59bc7f80c71002af84d46662584e34cf1db751b3 ?

  1. from config panel -> zha -> pick your plug -> Select "smartenergy_metering" cluster and read "divisor" and "multiplier" attributes. Make sure you get a value, so it gets cached
  2. get a shell inside the container and roll in changes from the commit above
  3. restart HA and monitor if you can reproduce it
hellcry37 commented 4 years ago

will do, check back when is done. Right now before any changes: divisor = 10000 multiplier = 1

hellcry37 commented 4 years ago

OK I've put your changes in smartenergy.py, I've managed to reproduce again after 4 restarts, values of: divisor = 10000 multiplier = 1 when the issue is "in effect"

What else I can try, for now I did not restart so the bug still happens

Adminiuga commented 4 years ago

what's the entity id of the entity with the issue? Just want to confirm the issues is with 0x0702 channel and not 0x0b04 I'm going to need debug enabled (see zha docs troubleshooting) and then the logs from the reset when the issue is occuring and need to know the NWK address of the device with the issue You can filter debug log, just make sure the following components are in the log:

hellcry37 commented 4 years ago

I've just put this in my configuration.yaml

logger:
  default: info
  logs:
    homeassistant.core: debug
    homeassistant.components.zha: debug
    # bellows.zigbee.application: debug
    # bellows.ezsp: debug
    zigpy: debug
    # zigpy_cc: debug
    # zigpy_deconz.zigbee.application: debug
    zigpy_deconz.api: debug
    zigpy_deconz: debug
    # zigpy_xbee.zigbee.application: debug
    # zigpy_xbee.api: debug
    # zigpy_zigate: debug
    # zhaquirks: debug

Restarted home assistant, fortunately issue was reproduced on the first try, unfortunately logs are empty.

What I am doing wrong?

Nwk: 0x393f - device with issue Nwk: 0xc9ff - device without issue

I did a few restarts, i can say that bug happen on all of them, smartenergy.py is still the modified version, did not change it back, still no logs. ZHA logs will appear in home assistant log or in other place?

Adminiuga commented 4 years ago

you don't have home-assistant.log in your config folder? ps: uncomment zigpy_deconz.zigbee.application in the logger config

hellcry37 commented 4 years ago

i do, home-assistant.log is there but empty

hellcry37 commented 4 years ago

Ah no my apologize, log has a lot of data, just ha doesn't show it Logs coming soon just have to reproduce the bug, doing restarts :)

hellcry37 commented 4 years ago

Yah now the second plug shows the wrong value and the first one is ok :) log is to big, cant paste it, what do you need in it, I'll search and paste it

hellcry37 commented 4 years ago

log.txt log attached (in this log TV one shows the wrong value not AC one)

Adminiuga commented 4 years ago

if in a linux shell, you could do egrep -e 'homeassistant.core|zha|zigpy|deconz' home-assistant.log > filtered-log.txt and DM or post a link

Adminiuga commented 4 years ago

for the attached log, is the Nwk: 0x393f still the device with the issue?

hellcry37 commented 4 years ago

nop, is the other one :)

Adminiuga commented 4 years ago

for all devices with the issue, after the HA was running for about 20min, read the multiplier and divisor to seed the cache.

hellcry37 commented 4 years ago

ok will do a few more restarts, wait and i'll be back in 20 minutes

hellcry37 commented 4 years ago

managed to make again device with nwk 0x393f to bug. - this is wrong seem that is still Nwk: 0xc9ff with issue

log attached: log_issue_device_nwk_0x393f.txt

Waiting for that 20 minutes to read the values asked

Adminiuga commented 4 years ago

from the 1st debug log you submitted, is it the sensor.heiman_smartplug_2_smartenergy_metering entity_id having the issue or is it the other one on 0x0b04 cluster entity_id=sensor.heiman_smartplug_2_electrical_measurement?

hellcry37 commented 4 years ago

first and second logs both show sensor.heiman_smartplug_2_electrical_measurement

electrical_measurement being the one with issues on both devices seems (the measure current consumption in Watts - https://en.wikipedia.org/wiki/Watt)

hellcry37 commented 4 years ago

device: plug2 tv one Nwk: 0xc9ff divisor: 10000 multiplier: 1 Nothing changed

My tv shows it consumes now 682 Watts :)

Adminiuga commented 4 years ago

ok, so this is the other one, the one on 0x0b04 cluster

hellcry37 commented 4 years ago

at the beginning was plug1 AC that had issues, now is plug2 TV with issues, no idea where to get this 0x0b04.

Both logs sent show issue on plug2 tv

hellcry37 commented 4 years ago

on metric cluster both devices have id: 0x0702

Adminiuga commented 4 years ago

at the beginning was plug1 AC that had issues, now is plug2 TV with issues, no idea where to get this 0x0b04

just needed the entity_id (if it wasn't changed) then it would have the name of the cluster. those plugs have two different clusters which show energy use, one in kW other just W

Can you do the following:

  1. in config panel -> zha -> pick devices with issues -> pick 0x0b04 cluster (Electrical measurement) and read the following attributes:

and restart HA. as long as it reads those attrs at least once, it is going to keep cached values so the issue shouldn't occur.

hellcry37 commented 4 years ago

plug2 TV - this one currently has the bug ac_power_divisor: 10 ac_power_multiplier: 1 power_divisor: None power_multiplier: None

plug1 AC - this one is ok at this moment ac_power_divisor: 10 ac_power_multiplier: 1 power_divisor: None power_multiplier: None

they are the same.

Doing the changes now and restart

hellcry37 commented 4 years ago

after 6 restarts values of: ac_power_divisor: 10 ac_power_multiplier: 1 power_divisor: None power_multiplier: None

are the same, devices did not manifest the bug in any of the restarts

last change was await self.fetch_config(True) in homeautomation.py

hellcry37 commented 4 years ago

I'll try a bit more tomorrow some restarts and come back with feedback, thanks @Adminiuga , unless you want me to try something else?

Adminiuga commented 4 years ago

just give it a few more restarts tomorrow and report back. I'll submit a PR so it would make into next version.

Adminiuga commented 4 years ago

this is continuation of https://github.com/home-assistant/core/issues/35919

hellcry37 commented 4 years ago

everything works as expected after the two changes and many many restarts.

Adminiuga commented 4 years ago

excellent, the fix should be in 0.112.0 release then.