Ikea switches and remotes consume batteries very fast and stop responding after replacing the batteries

ygreq commented 3 years ago

The problem

Running Ikea on/off switches and remote controls with ZHA and Sonoff ZB Bridge on HA running on Proxmox. First of all, I want to mention the fact that the Ikea devices consume the batteries much much faster that if I were to use them with the Tradfri Bridge. It is hard for me to quantify, but believe me when I say that they consume the batteries at least 5 times faster while in ZHA

The second problem I’ve been having since at least a few weeks now with Ikea remote controls and on/off switches is the fact that they stop responding after having replaced their batteries. Even after a few hours. I also checked them in Events via zha_event. It remains unavailable. The solution I found is to pair them again. Once paired, they are recognized by the system with their old names I set. The other devices from Ikea that still have batteries are working ok.

Environment

Home Assistant Core release with the issue: 0.118.4
Last working Home Assistant Core release (if known): Not known
Operating environment (OS/Container/Supervised/Core): Proxmox
Integration causing this issue: ZHA with Sonoff ZB Bridge
Link to integration documentation on our website: https://www.home-assistant.io/integrations/zha/

Problem-relevant `configuration.yaml`

Traceback/Error logs

This is what I get when re-pairing one Ikea remote control

Device 0x3f48 (00:0d:6f:ff:fe:11:b4:06) joined the network
Device 00:0d:6f:ff:fe:11:b4:06 changed id (0xc339 => 0x3f48)
device - 0x3f48:00:0d:6f:ff:fe:11:b4:06 entering async_device_initialized - is_new_join: False
device - 0x3f48:00:0d:6f:ff:fe:11:b4:06 has been reset and re-added or its nwk address changed
skipping discovery for previously discovered device - 0x3f48:00:0d:6f:ff:fe:11:b4:06
[0x3f48](TRADFRI remote control): started configuration
[0x3f48:ZDO](TRADFRI remote control): 'async_configure' stage succeeded
[0x3f48] Extending timeout for 0x55 request
[0x3f48] Extending timeout for 0x57 request
[0x3f48] Extending timeout for 0x59 request
Device 00:0d:6f:ff:fe:11:b4:06 already exists. Updating it.
Device 0x3f48 (00:0d:6f:ff:fe:11:b4:06) joined the network
Skip initialization for existing device 00:0d:6f:ff:fe:11:b4:06
Device 0x3f48 (00:0d:6f:ff:fe:11:b4:06) joined the network
Skip initialization for existing device 00:0d:6f:ff:fe:11:b4:06
[0x3f48:zdo] ZDO request ZDOCmd.Device_annce: [0x3F48, 00:0d:6f:ff:fe:11:b4:06, 128]
[0x3f48](TRADFRI remote control): started initialization
[0x3f48:ZDO](TRADFRI remote control): 'async_initialize' stage succeeded
[0x3f48:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
[0x3f48:zdo] Unsupported ZDO request:ZDOCmd.Node_Desc_req
[0x3f48:1:0x1000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=85 command_id=65>
[0x3f48:1:0x1000]: bound 'lightlink' cluster: None
[0x3f48:1:0x1000]: finished channel configuration
[0x3f48:1:0x0001]: bound 'power' cluster: Status.SUCCESS
[0x3f48] Extending timeout for 0x5b request
[0x3f48] Extending timeout for 0x5d request
[0x3f48:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
[0x3f48:1:0x0000]: finished channel configuration
[0x3f48] Extending timeout for 0x5f request
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=91 command_id=Command.Configure_Reporting_rsp>
[0x3f48:1:0x0001]: reporting 'battery_voltage' attr on 'power' cluster: 3600/10800/1: Result: '[[ConfigureReportingResponseRecord(status=0)]]'
[0x3f48] Extending timeout for 0x61 request
[0x3f48:1:0x0020] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=93 command_id=Command.Write_Attributes_rsp>
[0x3f48:1:0x0020]: 3300.0s check-in interval set: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
[0x3f48] Extending timeout for 0x63 request
[0x3f48:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [180, <Bool.true: 1>]
[0x3f48:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=2 command_id=1>
[0x3f48:1:0x0003] ZCL request 0x0001: []
[0x3f48:1:0x0003] No handler for cluster command 1
[0x3f48:1:0x0003]: received 'identify_query' command with [] args on cluster_id '3' tsn '2'
[0x3f48:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=95 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0000]: initializing channel: from_cache: False
[0x3f48] Extending timeout for 0x65 request
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=97 command_id=Command.Configure_Reporting_rsp>
[0x3f48:1:0x0001]: reporting 'battery_percentage_remaining' attr on 'power' cluster: 3600/10800/1: Result: '[[ConfigureReportingResponseRecord(status=0)]]'
[0x3f48:1:0x0001]: finished channel configuration
[0x3f48] Extending timeout for 0x67 request
[0x3f48:1:0x0020]: bound 'poll_control' cluster: Status.SUCCESS
[0x3f48:1:0x0020]: finished channel configuration
[0x3f48] Extending timeout for 0x69 request
[0x3f48:1:0x0008]: bound 'level' cluster: Status.SUCCESS
[0x3f48:1:0x0008]: finished channel configuration
[0x3f48] Extending timeout for 0x6b request
[0x3f48:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0x3f48:1:0x0006]: finished channel configuration
[0x3f48:1:0x1000]: initializing channel: from_cache: False
[0x3f48] Extending timeout for 0x6d request
[0x3f48:1:0x0019]: bound 'ota' cluster: Status.SUCCESS
[0x3f48:1:0x0019]: finished channel configuration
[0x3f48] Extending timeout for 0x6f request
[0x3f48:1:0x0005]: bound 'scenes' cluster: Status.SUCCESS
[0x3f48:1:0x0005]: finished channel configuration
[0x3f48:1:0x0020]: initializing channel: from_cache: False
[0x3f48:1:0x0008]: initializing channel: from_cache: False
[0x3f48:1:0x1000]: 'async_configure' stage succeeded
[0x3f48:1:0x0001]: 'async_configure' stage succeeded
[0x3f48:1:0x0000]: 'async_configure' stage succeeded
[0x3f48:1:0x0020]: 'async_configure' stage succeeded
[0x3f48:1:0x0008]: 'async_configure' stage succeeded
[0x3f48:1:0x0006]: 'async_configure' stage succeeded
[0x3f48:1:0x0019]: 'async_configure' stage succeeded
[0x3f48:1:0x0005]: 'async_configure' stage succeeded
[0x3f48:1:0x0006]: initializing channel: from_cache: False
[0x3f48:1:0x0019]: initializing channel: from_cache: False
[0x3f48](TRADFRI remote control): completed configuration
[0x3f48](TRADFRI remote control): stored in registry: ZhaDeviceEntry(name='IKEA of Sweden TRADFRI remote control', ieee='00:0d:6f:ff:fe:11:b4:06', last_seen=1607175864.4921234)
[0x3f48] Extending timeout for 0x71 request
[0x3f48:1:0x0005]: initializing channel: from_cache: False
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=109 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=111 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0001]: initializing channel: from_cache: False
[0x3f48] Extending timeout for 0x73 request
[0x3f48:1:0x0000]: initializing channel: from_cache: False
[0x3f48:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=113 command_id=Command.Default_Response>
[0x3f48:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: [64, <Status.SUCCESS: 0>]
[0x3f48](TRADFRI remote control): started initialization
[0x3f48:ZDO](TRADFRI remote control): 'async_initialize' stage succeeded
[0x3f48:1:0x1000]: initializing channel: from_cache: False
[0x3f48] Extending timeout for 0x75 request
[0x3f48] Extending timeout for 0x77 request
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=115 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0020]: initializing channel: from_cache: False
[0x3f48:1:0x0008]: initializing channel: from_cache: False
[0x3f48:1:0x1000]: 'async_initialize' stage succeeded
[0x3f48:1:0x0001]: 'async_initialize' stage succeeded
[0x3f48:1:0x0000]: 'async_initialize' stage succeeded
[0x3f48:1:0x0020]: 'async_initialize' stage succeeded
[0x3f48:1:0x0008]: 'async_initialize' stage succeeded
[0x3f48:1:0x0006]: 'async_initialize' stage succeeded
[0x3f48:1:0x0019]: 'async_initialize' stage succeeded
[0x3f48:1:0x0005]: 'async_initialize' stage succeeded
[0x3f48:1:0x0006]: initializing channel: from_cache: False
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=117 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0019]: initializing channel: from_cache: False
[0x3f48](TRADFRI remote control): power source: Battery or Unknown
[0x3f48](TRADFRI remote control): completed initialization
[0x3f48:1:0x0005]: initializing channel: from_cache: False
[0x3f48:1:0x0001]: initializing channel: from_cache: False
[0x3f48] Extending timeout for 0x79 request
[0x3f48:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=119 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x0000]: initializing channel: from_cache: False
[0x3f48:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=121 command_id=Command.Read_Attributes_rsp>
[0x3f48:1:0x1000]: 'async_initialize' stage succeeded
[0x3f48:1:0x0001]: 'async_initialize' stage succeeded
[0x3f48:1:0x0000]: 'async_initialize' stage succeeded
[0x3f48:1:0x0020]: 'async_initialize' stage succeeded
[0x3f48:1:0x0008]: 'async_initialize' stage succeeded
[0x3f48:1:0x0006]: 'async_initialize' stage succeeded
[0x3f48:1:0x0019]: 'async_initialize' stage succeeded
[0x3f48:1:0x0005]: 'async_initialize' stage succeeded
[0x3f48](TRADFRI remote control): power source: Battery or Unknown
[0x3f48](TRADFRI remote control): completed initialization

Additional information

Thank you for all your help!

probot-home-assistant[bot] commented 3 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)}}

macfly92 commented 3 years ago

Ok, my first thought was my pack of CR2032 was faulty, but I have the same problem as you. Thanks you to report it.

Battery drain in 2 or 3 days and I'm not be able to get it back with a battery replacement. I need to reset and pair it again too. I have other scene switchs (Xiaomi) and the problem seem to be only for my ON/OFF Ikea Tradfri switch. I don't have other Ikea remotes.

HA Version : 0.118.3 Core on Docker HomeMade Zigbee Dongle : Telegesis ETRX357USB

Please let me know if I can do some tests, in the meantime, I will wait before putting another battery in it ...

MattWestb commented 3 years ago

I was buying 3 x E27 WW + E1743 in february and after pairing (IKEA GW) and upgrade 2 switches wos around 70 - 80 % battery left. The 3d was nearly empty. New battery and pairing in deCONZ and empty after one week on the table without being used. New better and binding to bulb and little testing and 2 weeks batter was out. I was giving it back then the shutdown was over and getting one new family pack and the new E1743 is more normal. Must being somthing wrong in the RF part or it cant sleeping as it should.

My recommendation if its very power hungry returning it and getting one new one.

ygreq commented 3 years ago

I was buying 3 x E27 WW + E1743 in february and after pairing (IKEA GW) and upgrade 2 switches wos around 70 - 80 % battery left. The 3d was nearly empty. New battery and pairing in deCONZ and empty after one week on the table without being used. New better and binding to bulb and little testing and 2 weeks batter was out. I was giving it back then the shutdown was over and getting one new family pack and the new E1743 is more normal. Must being somthing wrong in the RF part or it cant sleeping as it should.

My recommendation if its very power hungry returning it and getting one new one.

Sorry, Matt, but I don't quite understand everything you say. But if I understand correctly, you say that there might be some problems with some Ikea Switches and Remotes. I have to say that I used the respective switches and remotes with the Ikea Tradfri Gateway and I did not have this problem. But now with ZHA and Sonoff ZB Bridge the batteries get emptied very fast without me pushing any buttons. Like you say most probably, the system (ZHA) is forcing them not to go in deep sleep (considering this is what zigbee devices to to save battery, right?).

So no, these remotes and switches are not faulty.

MattWestb commented 3 years ago

Normally not but for my 3 new and one was killing the battery very fast (I have 8 of them). I agree with you that E1743s battery is lasting lasting longer on the IKEA GW. Tasmota have disabling attribute reporting for IKEA switches because of the battery problem.

Adminiuga commented 3 years ago

I have two E1743 in production for at least two months and haven't changed the battery yet. The only problem, if nobody uses the remote, then we t doesn't report battery often enough and zha marks the device as offline. But any press on the remote, zha receives data and marks it online again.

I don't know if the problem is specific to Sonoff NCP image or not.

MattWestb commented 3 years ago

I have my kitchen with 2 E1743 and one new 5 button remote still on IKEA GW (ZHA have not the scene working for the WS spots). First E1743 little more then 10 month and the second around 15 month running on the original batteries. Remote still on original ones after 1.5 year. I dont remember if they was upgraded or original FW. Some very cheap cels can having under 3.0 V then taking them out of the package and that is nearly zero in lifetime of the battery.

By the way the IKEA batteries is not very god but also not very bad but pretty OK for the price (Its no VERTA ones also by price) and if its not very old more than 3V.

If sleeping end device have god connection to one router in the near its using very low power and also dont need stretching for better one all the time that easting current.

Tasmota user normally dont have much routers more HA sensors (exceptions gibt always).

ygreq commented 3 years ago

@Adminiuga , I am guessing you are using some other device instead of the Sonoff ZB Bridge?

BTW, you gave me an idea. I should track the last time battery has been reported on a newly changed battery. If it reports more often, then this must be the problem. And this is why the battery depletes that fast. This is what I am expecting anyway.

May I ask what was the code in Lovelace to have this reported? LE: Found it: secondary_info: last-changed

As you can see in the report, and about what @macfly92 is reporting as well, we have 2 problems, the second one being that once battery is depleted and we change it, the device does not come back online even if we leave it for hours or we press on it many times. We have to reset it and pair it again in order for the device to become available again in the network

Thank you so much!

MattWestb commented 3 years ago

The last point i think its the personality of the firmware. I think its 50/50 chance that is must being repaired after battery being killed also with IKEA GW (1 tome of 2 batteries changes).

If the voltage is to low the device cant saving the security frame counter in the flash after acking one frame and it can going out of sync.

ygreq commented 3 years ago

@MattWestb, like before, I don't know if I understand everything you say :) But I do thank you for trying to help!

Adminiuga commented 3 years ago

Enable debug logging.and monitoring how many messages associated with the device are sent and received. My guess, since it won't rejoin after battery was depleted, its because the device nis constantly leaving and rejoin, until battery is depleted and it fails the rejoin

ygreq commented 3 years ago

Can you please let me know how to enable debug logging and monitoring, please?

Thank you very much!!

I also asked for help lots of months ago :/

https://community.home-assistant.io/t/debug-logging-in-zha/236982

ygreq commented 3 years ago

Or maybe I should ask where should I read the ZHA logs?

Is this it config/logs ?

I found some errors here related to zigbee. Any idea what it means?

I don't know it it is repeating itself so I copied 2 examples:

2020-12-06 18:16:45 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 65535,COUNTER_MAC_TX_BROADCAST: 65535,COUNTER_MAC_RX_UNICAST: 65535,COUNTER_MAC_TX_UNICAST_SUCCESS: 12971,COUNTER_MAC_TX_UNICAST_RETRY: 29902,COUNTER_MAC_TX_UNICAST_FAILED: 10168,COUNTER_APS_DATA_RX_BROADCAST: 484,COUNTER_APS_DATA_TX_BROADCAST: 484,COUNTER_APS_DATA_RX_UNICAST: 7797,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 6796,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2522,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1165,COUNTER_ROUTE_DISCOVERY_INITIATED: 1135,COUNTER_NEIGHBOR_ADDED: 20,COUNTER_NEIGHBOR_REMOVED: 10,COUNTER_NEIGHBOR_STALE: 440,COUNTER_JOIN_INDICATION: 15,COUNTER_CHILD_REMOVED: 9,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2411,COUNTER_BROADCAST_TABLE_FULL: 158,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0

2020-12-06 18:17:06 DEBUG (MainThread) [bellows.zigbee.application] EZSP Counters: COUNTER_MAC_RX_BROADCAST: 65535,COUNTER_MAC_TX_BROADCAST: 65535,COUNTER_MAC_RX_UNICAST: 65535,COUNTER_MAC_TX_UNICAST_SUCCESS: 12971,COUNTER_MAC_TX_UNICAST_RETRY: 29902,COUNTER_MAC_TX_UNICAST_FAILED: 10168,COUNTER_APS_DATA_RX_BROADCAST: 484,COUNTER_APS_DATA_TX_BROADCAST: 484,COUNTER_APS_DATA_RX_UNICAST: 7797,COUNTER_APS_DATA_TX_UNICAST_SUCCESS: 6796,COUNTER_APS_DATA_TX_UNICAST_RETRY: 2522,COUNTER_APS_DATA_TX_UNICAST_FAILED: 1165,COUNTER_ROUTE_DISCOVERY_INITIATED: 1135,COUNTER_NEIGHBOR_ADDED: 20,COUNTER_NEIGHBOR_REMOVED: 10,COUNTER_NEIGHBOR_STALE: 440,COUNTER_JOIN_INDICATION: 15,COUNTER_CHILD_REMOVED: 9,COUNTER_ASH_OVERFLOW_ERROR: 0,COUNTER_ASH_FRAMING_ERROR: 0,COUNTER_ASH_OVERRUN_ERROR: 0,COUNTER_NWK_FRAME_COUNTER_FAILURE: 0,COUNTER_APS_FRAME_COUNTER_FAILURE: 0,COUNTER_UTILITY: 0,COUNTER_APS_LINK_KEY_NOT_AUTHORIZED: 0,COUNTER_NWK_DECRYPTION_FAILURE: 0,COUNTER_APS_DECRYPTION_FAILURE: 0,COUNTER_ALLOCATE_PACKET_BUFFER_FAILURE: 0,COUNTER_RELAYED_UNICAST: 0,COUNTER_PHY_TO_MAC_QUEUE_LIMIT_REACHED: 0,COUNTER_PACKET_VALIDATE_LIBRARY_DROPPED_COUNT: 0,COUNTER_TYPE_NWK_RETRY_OVERFLOW: 0,COUNTER_PHY_CCA_FAIL_COUNT: 2411,COUNTER_BROADCAST_TABLE_FULL: 158,COUNTER_PTA_LO_PRI_REQUESTED: 0,COUNTER_PTA_HI_PRI_REQUESTED: 0,COUNTER_PTA_LO_PRI_DENIED: 0,COUNTER_PTA_HI_PRI_DENIED: 0,COUNTER_PTA_LO_PRI_TX_ABORTED: 0,COUNTER_PTA_HI_PRI_TX_ABORTED: 0,COUNTER_ADDRESS_CONFLICT_SENT: 0

Adminiuga commented 3 years ago

Those are not errors, ignore those.
If you are posting a link, can you post a link which leads somewhere?
when zigpy receives a message from a device on the network, it would normally log that message with NWK address of the device. e.g a device with NWK address 0x2d1c

you can filter the log with grep, like grep -i 0x2d1c /config/home-assistant.log and you'll get all the messages related to the device

2020-12-07 23:35:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=152), 240, -40, 0x2d1c, 255, 255, b'\x086\n\x00\x04*\x00\x00\x00']
2020-12-07 23:35:28 DEBUG (MainThread) [zigpy.zcl] [0x2d1c:1:0x0702] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=54 command_id=Command.Report_Attributes>
2020-12-07 23:35:28 DEBUG (MainThread) [zigpy.zcl] [0x2d1c:1:0x0702] ZCL request 0x000a: [[Attribute(attrid=1024, value=<TypeValue type=int24s, value=0>)]]
2020-12-07 23:35:28 DEBUG (MainThread) [zigpy.zcl] [0x2d1c:1:0x0702] Attribute report received: instantaneous_demand=0

ygreq commented 3 years ago

Finally I managed to do it. Here are the logs related to the remote I recently changed the battery to. Let me know if based on this info, you manage to figure out what the problem is. Nwk is 0x3f43 for this case

` Line 670: 2020-12-08 20:55:06 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0000] Attribute id: 5 value: TRADFRI remote control Line 704: 2020-12-08 20:55:06 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0000] Attribute id: 4 value: IKEA of Sweden Line 1029: 2020-12-08 20:55:07 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0000] Attribute id: 5 value: TRADFRI remote control Line 1113: 2020-12-08 20:55:08 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0000] Attribute id: 7 value: 3 Line 1114: 2020-12-08 20:55:08 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0001] Attribute id: 32 value: 30 Line 1115: 2020-12-08 20:55:08 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0001] Attribute id: 33 value: 174 Line 1138: 2020-12-08 20:55:08 DEBUG (MainThread) [zigpy.appdb] [0x3f43:1:0x0000] Attribute id: 4 value: IKEA of Sweden Line 1529: 2020-12-08 20:55:21 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x3f43](IKEA of Sweden TRADFRI remote control) restored as 'available', last seen: 1:56:07 ago Line 1647: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3f43](TRADFRI remote control): started initialization Line 1648: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:ZDO](TRADFRI remote control): 'async_initialize' stage succeeded Line 1657: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0001]: initializing channel: from_cache: True Line 1658: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0020]: initializing channel: from_cache: True Line 1659: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x1000]: initializing channel: from_cache: True Line 1660: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0000]: initializing channel: from_cache: True Line 1661: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0008]: initializing channel: from_cache: True Line 1662: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0006]: initializing channel: from_cache: True Line 1663: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0019]: initializing channel: from_cache: True Line 1664: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0005]: initializing channel: from_cache: True Line 1673: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0001]: 'async_initialize' stage succeeded Line 1674: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0020]: 'async_initialize' stage succeeded Line 1675: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x1000]: 'async_initialize' stage succeeded Line 1676: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0000]: 'async_initialize' stage succeeded Line 1677: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0008]: 'async_initialize' stage succeeded Line 1678: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0006]: 'async_initialize' stage succeeded Line 1679: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0019]: 'async_initialize' stage succeeded Line 1680: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0005]: 'async_initialize' stage succeeded Line 1683: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3f43](TRADFRI remote control): power source: Battery or Unknown Line 1684: 2020-12-08 20:55:22 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3f43](TRADFRI remote control): completed initialization Line 5772: 2020-12-08 21:15:24 DEBUG (MainThread) [zigpy.neighbor] [0x0000] request status: Status.SUCCESS. response: Neighbors(entries=7, start_index=6, neighbor_table_list=[Neighbor(extended_pan_id=cc:cc:cc:cc:d7:12:cf:a4, ieee=00:0d:6f:ff:fe:11:b4:06, nwk=0x3f43, packed=18, permit_joining=<PermitJoins.NotAccepting: 0>, depth=1, lqi=0)]) Line 29334: 2020-12-09 00:55:12 DEBUG (MainThread) [zigpy.neighbor] [0x0000] request status: Status.SUCCESS. response: Neighbors(entries=10, start_index=9, neighbor_table_list=[Neighbor(extended_pan_id=cc:cc:cc:cc:d7:12:cf:a4, ieee=00:0d:6f:ff:fe:11:b4:06, nwk=0x3f43, packed=18, permit_joining=<PermitJoins.NotAccepting: 0>, depth=1, lqi=0)]) Line 30288: 2020-12-09 01:00:01 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3f43](TRADFRI remote control): Attempting to checkin with device - missed checkins: 1 Line 30289: 2020-12-09 01:00:01 DEBUG (MainThread) [zigpy.device] [0x3f43] Extending timeout for 0xee request Line 30290: 2020-12-09 01:00:01 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:0d:6f:ff:fe:11:b4:06/0x3f43 Line 30293: 2020-12-09 01:00:01 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x3f43, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=238), 239, b'\x00\xee\x00\x04\x00') Line 30297: 2020-12-09 01:00:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=244), 192, -52, 0x3f43, 255, 255, b'\x18\xee\x01\x04\x00\x00B\x0eIKEA of Sweden'] Line 30298: 2020-12-09 01:00:04 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=238 command_id=Command.Read_Attributes_rsp> Line 33826: 2020-12-09 01:35:51 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=245), 168, -58, 0x3f43, 255, 255, b'\x01>\x02'] Line 33827: 2020-12-09 01:35:51 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=62 command_id=2> Line 33828: 2020-12-09 01:35:51 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 33829: 2020-12-09 01:35:51 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 43953: 2020-12-09 04:57:01 DEBUG (MainThread) [zigpy.neighbor] [0x0000] request status: Status.SUCCESS. response: Neighbors(entries=7, start_index=6, neighbor_table_list=[Neighbor(extended_pan_id=cc:cc:cc:cc:d7:12:cf:a4, ieee=00:0d:6f:ff:fe:11:b4:06, nwk=0x3f43, packed=18, permit_joining=<PermitJoins.NotAccepting: 0>, depth=1, lqi=190)]) Line 47020: 2020-12-09 05:56:25 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=32, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=246), 180, -55, 0x3f43, 255, 255, b'\t@\x00'] Line 47021: 2020-12-09 05:56:25 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0020] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=64 command_id=0> Line 47022: 2020-12-09 05:56:25 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0020] ZCL request 0x0000: [] Line 47023: 2020-12-09 05:56:25 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0020] No handler for cluster command 0 Line 47024: 2020-12-09 05:56:25 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0020]: Received 64 tsn command 'checkin': [] Line 47026: 2020-12-09 05:56:25 DEBUG (MainThread) [zigpy.device] [0x3f43] Extending timeout for 0x40 request Line 47027: 2020-12-09 05:56:25 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:0d:6f:ff:fe:11:b4:06/0x3f43 Line 47030: 2020-12-09 05:56:25 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x3f43, EmberApsFrame(profileId=260, clusterId=32, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=64), 254, b'\x01@\x00\x01\x08\x00') Line 47033: 2020-12-09 05:56:27 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=32, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=247), 180, -55, 0x3f43, 255, 255, b'\x08@\x0b\x00\x00'] Line 47034: 2020-12-09 05:56:27 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0020] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=64 command_id=Command.Default_Response> Line 47037: 2020-12-09 05:56:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0020]: executed 'checkin_response' command with args: '(True, 8)' kwargs: '{'tsn': 64}' result: [0, <Status.SUCCESS: 0>] Line 47038: 2020-12-09 05:56:27 DEBUG (MainThread) [zigpy.device] [0x3f43] Extending timeout for 0xff request Line 47039: 2020-12-09 05:56:27 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:0d:6f:ff:fe:11:b4:06/0x3f43 Line 47042: 2020-12-09 05:56:27 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x3f43, EmberApsFrame(profileId=260, clusterId=32, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=255), 0, b'\x01\xff\x02\x18\x00\x00\x00') Line 47045: 2020-12-09 05:56:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=32, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=248), 184, -54, 0x3f43, 255, 255, b'\x08\xff\x0b\x02\x00'] Line 47046: 2020-12-09 05:56:28 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0020] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=255 command_id=Command.Default_Response> Line 47049: 2020-12-09 05:56:28 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3f43:1:0x0020]: executed 'set_long_poll_interval' command with args: '(24,)' kwargs: '{}' result: [2, <Status.SUCCESS: 0>] Line 55888: 2020-12-09 08:59:26 DEBUG (MainThread) [zigpy.neighbor] [0x0000] request status: Status.SUCCESS. response: Neighbors(entries=7, start_index=6, neighbor_table_list=[Neighbor(extended_pan_id=cc:cc:cc:cc:d7:12:cf:a4, ieee=00:0d:6f:ff:fe:11:b4:06, nwk=0x3f43, packed=18, permit_joining=<PermitJoins.NotAccepting: 0>, depth=1, lqi=188)]) Line 67012: 2020-12-09 11:57:20 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3f43](TRADFRI remote control): Attempting to checkin with device - missed checkins: 1 Line 67013: 2020-12-09 11:57:20 DEBUG (MainThread) [zigpy.device] [0x3f43] Extending timeout for 0x42 request Line 67014: 2020-12-09 11:57:20 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:0d:6f:ff:fe:11:b4:06/0x3f43 Line 67017: 2020-12-09 11:57:20 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x3f43, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=66), 67, b'\x00B\x00\x04\x00') Line 67021: 2020-12-09 11:57:23 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=249), 188, -53, 0x3f43, 255, 255, b'\x18B\x01\x04\x00\x00B\x0eIKEA of Sweden'] Line 67022: 2020-12-09 11:57:23 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=66 command_id=Command.Read_Attributes_rsp> Line 68373: 2020-12-09 12:10:32 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=250), 192, -52, 0x3f43, 255, 255, b'\x01C\x02'] Line 68374: 2020-12-09 12:10:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=67 command_id=2> Line 68375: 2020-12-09 12:10:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 68376: 2020-12-09 12:10:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 70019: 2020-12-09 12:25:32 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=251), 184, -54, 0x3f43, 255, 255, b'\x01D\x02'] Line 70020: 2020-12-09 12:25:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=68 command_id=2> Line 70021: 2020-12-09 12:25:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 70022: 2020-12-09 12:25:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 74159: 2020-12-09 13:01:52 DEBUG (MainThread) [zigpy.neighbor] [0x0000] request status: Status.SUCCESS. response: Neighbors(entries=10, start_index=9, neighbor_table_list=[Neighbor(extended_pan_id=cc:cc:cc:cc:d7:12:cf:a4, ieee=00:0d:6f:ff:fe:11:b4:06, nwk=0x3f43, packed=18, permit_joining=<PermitJoins.NotAccepting: 0>, depth=1, lqi=188)]) Line 83009: 2020-12-09 14:18:14 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=252), 168, -58, 0x3f43, 255, 255, b'\x01F\x02'] Line 83010: 2020-12-09 14:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=70 command_id=2> Line 83011: 2020-12-09 14:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 83012: 2020-12-09 14:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 84889: 2020-12-09 14:33:32 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=253), 172, -57, 0x3f43, 255, 255, b'\x01G\x02'] Line 84890: 2020-12-09 14:33:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=71 command_id=2> Line 84891: 2020-12-09 14:33:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 84892: 2020-12-09 14:33:32 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 84954: 2020-12-09 14:33:35 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=254), 168, -58, 0x3f43, 255, 255, b'\x01H\x02'] Line 84955: 2020-12-09 14:33:35 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=72 command_id=2> Line 84956: 2020-12-09 14:33:35 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 84957: 2020-12-09 14:33:35 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 85152: 2020-12-09 14:35:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=255), 168, -58, 0x3f43, 255, 255, b'\x01I\x02'] Line 85153: 2020-12-09 14:35:00 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=73 command_id=2> Line 85154: 2020-12-09 14:35:00 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 85155: 2020-12-09 14:35:00 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 85200: 2020-12-09 14:35:13 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=0), 164, -59, 0x3f43, 255, 255, b'\x01J\x02'] Line 85201: 2020-12-09 14:35:13 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=74 command_id=2> Line 85202: 2020-12-09 14:35:13 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 85203: 2020-12-09 14:35:13 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 85227: 2020-12-09 14:35:15 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=1), 160, -60, 0x3f43, 255, 255, b'\x01K\x02'] Line 85228: 2020-12-09 14:35:15 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=75 command_id=2> Line 85229: 2020-12-09 14:35:15 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 85230: 2020-12-09 14:35:15 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2 Line 85664: 2020-12-09 14:37:53 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=2), 180, -55, 0x3f43, 255, 255, b'\x01L\x02'] Line 85665: 2020-12-09 14:37:53 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=76 command_id=2> Line 85666: 2020-12-09 14:37:53 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] ZCL request 0x0002: [] Line 85667: 2020-12-09 14:37:53 DEBUG (MainThread) [zigpy.zcl] [0x3f43:1:0x0006] No handler for cluster command 2

`

Adminiuga commented 3 years ago

Log looks fine, but it's too short, anyway. Keep the logs running and save the logs offline, before every HA restart, cause restarting HA erases the logs.

ygreq commented 3 years ago

Ok. I will let it add some more data. Should I put the next paste somewhere else like bitbucket or here considering the size?

Thank you very much!

MattWestb commented 3 years ago

@ygreq You can Zipping it and attaching it the message (Drag and paste). I doing like that then having firmware files that need being looked at.

By the way good working !!!

Adminiuga commented 3 years ago

what firmware version does the device report

save the logs then run the following to filter egrep -i -e 'trustCenter|idConflict|70:8d:45|0xba48' home-assistant.log just replace 70:8d:45 with last digits of the remote IEEE address and replace 0xba48 with your remote NWK address

zip the file and DM me on HA discord

ygreq commented 3 years ago

Device info TRADFRI remote control by IKEA of Sweden Zigbee Coordinator Firmware: 0x23014631

Ok, I will let it run for 1 or 2 more days and than do as you asked.

Adminiuga commented 3 years ago

What's the exact model number?

ygreq commented 3 years ago

The one exemplified above is e1810, but I also have E1743 but create the same problems

Mariusthvdb commented 3 years ago

recognizing this, but only on certain motion sensors. Have quite a few that are reporting full to 60% a couple that have been on 30+ for a rather long period. 2 explicit sensors always deteriorate within the day! Seems to be related to the place in the Home, because for those 2 it doesn't matter if I use the older or the newer model motion sensor.

Also, as I have bought a battery level meter for these devices especially, they dont report the true value of the battery. Had one report 5%, while in fact it was practically in the Alecto Good green sector of the meter...

Not sure if this helps

on the official Ikea Hub btw.

MattWestb commented 3 years ago

I use Hue Essentials app and getting the batter % the from the IKEA GW :-))

The IKEA ones both new and old modelle is little tricky of the state of the batteries, if one is week it can start triggering motion at level between 70 and 60 % battery level. I still have the original batteries in one new and old one that is connected to IKEA GW but the ones that was connected to deCONZ and testing Bellows to ZHA is all being exchanged for some months ago but they have being paired many many times for testing.

Also then changing batteries always putting 2 new ones from the same batch / type or it can being that one is falling faster and the other is lasting longer but cant being used then the summary of the voltage its failing to low.

Philips HUE I have not changing batteries after 2.5 year and one have 80% (perhaps falce reported) and the other 18% but I think they is not liking Zigbee 3 routers (Silabs ones) and sometimes they have periods and changing it parent like crazy and shushing on of the lowers LQI then having 8 better much nearer.

ygreq commented 3 years ago

More than 2 days ago, I noticed that the Ikea remote control I am monitoring finished the battery again. I measured the voltage and it is 2.3V instead of 3.27V of a new one. It lasted less than 2 weeks (~11 days). The thing is an Ikea switch that sits next to it and is used the same still has plenty of battery. :/

I put a new one las night. The remote did not connect to the network as it should (I tested it with zha_event). Today I paired it again to the network and only now it started to be recognized in the network.

As an extra check, I just changed the battery to another remote that still had battery and still worked. I needed to check that if I change the battery it will loose connection to the network as well. It worked perfectly. I did not have to pair it again to the network.

@Adminiuga , if you think there is nothing wrong with the battery consuming fast on some ikea devices, may I ask that you look into the fact that these devices need to be paired again once they finish their batteries and you put a new one? Thank you so much!

This is the code I got from pairing the remote again:

[0x0000:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [60, <Bool.false: 0>]
[0x05c8:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
[0x05c8:zdo] Unsupported ZDO request:ZDOCmd.Node_Desc_req
Device 0x6daa (00:0d:6f:ff:fe:11:b4:06) joined the network
Device 00:0d:6f:ff:fe:11:b4:06 changed id (0x3f48 => 0x6daa)
device - 0x6daa:00:0d:6f:ff:fe:11:b4:06 entering async_device_initialized - is_new_join: False
device - 0x6daa:00:0d:6f:ff:fe:11:b4:06 has been reset and re-added or its nwk address changed
skipping discovery for previously discovered device - 0x6daa:00:0d:6f:ff:fe:11:b4:06
[0x6daa](TRADFRI remote control): started configuration
[0x6daa:ZDO](TRADFRI remote control): 'async_configure' stage succeeded
[0x6daa] Extending timeout for 0x05 request
[0x6daa] Extending timeout for 0x07 request
[0x6daa] Extending timeout for 0x09 request
Device 00:0d:6f:ff:fe:11:b4:06 already exists. Updating it.
Device 0x6daa (00:0d:6f:ff:fe:11:b4:06) joined the network
Skip initialization for existing device 00:0d:6f:ff:fe:11:b4:06
Device 0x6daa (00:0d:6f:ff:fe:11:b4:06) joined the network
Skip initialization for existing device 00:0d:6f:ff:fe:11:b4:06
[0x6daa:zdo] ZDO request ZDOCmd.Device_annce: [0x6DAA, 00:0d:6f:ff:fe:11:b4:06, 128]
[0x6daa](TRADFRI remote control): started initialization
[0x6daa:ZDO](TRADFRI remote control): 'async_initialize' stage succeeded
[0x6daa:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
[0x6daa:zdo] Unsupported ZDO request:ZDOCmd.Node_Desc_req
[0x6daa:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [180, <Bool.true: 1>]
[0x6daa:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=0 command_id=1>
[0x6daa:1:0x0003] ZCL request 0x0001: []
[0x6daa:1:0x0003] No handler for cluster command 1
[0x6daa:1:0x0003]: received 'identify_query' command with [] args on cluster_id '3' tsn '0'
[0x6daa:1:0x0020] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=5 command_id=Command.Write_Attributes_rsp>
[0x6daa:1:0x0020]: 3300.0s check-in interval set: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
[0x6daa] Extending timeout for 0x0b request
[0x6daa:1:0x1000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=7 command_id=65>
[0x6daa:1:0x1000]: bound 'lightlink' cluster: None
[0x6daa:1:0x1000]: finished channel configuration
[0x6daa] Extending timeout for 0x0d request
[0x6daa:1:0x0020]: bound 'poll_control' cluster: Status.SUCCESS
[0x6daa:1:0x0020]: finished channel configuration
[0x6daa] Extending timeout for 0x0f request
[0x6daa:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
[0x6daa:1:0x0000]: finished channel configuration
[0x6daa] Extending timeout for 0x11 request
[0x6daa:1:0x0001]: bound 'power' cluster: Status.SUCCESS
[0x6daa] Extending timeout for 0x13 request
[0x6daa:1:0x0008]: bound 'level' cluster: Status.SUCCESS
[0x6daa:1:0x0008]: finished channel configuration
[0x6daa] Extending timeout for 0x15 request
[0x6daa:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=17 command_id=Command.Read_Attributes_rsp>
[0x6daa:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=19 command_id=Command.Configure_Reporting_rsp>
[0x6daa:1:0x0000]: initializing channel: from_cache: False
[0x6daa] Extending timeout for 0x17 request
[0x6daa:1:0x0001]: reporting 'battery_voltage' attr on 'power' cluster: 3600/10800/1: Result: '[[ConfigureReportingResponseRecord(status=0)]]'
[0x6daa] Extending timeout for 0x19 request
[0x6daa:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0x6daa:1:0x0006]: finished channel configuration
[0x6daa] Extending timeout for 0x1b request
[0x6daa:1:0x0019]: bound 'ota' cluster: Status.SUCCESS
[0x6daa:1:0x0019]: finished channel configuration
[0x6daa:1:0x0020]: initializing channel: from_cache: False
[0x6daa:1:0x1000]: initializing channel: from_cache: False
[0x6daa:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=25 command_id=Command.Configure_Reporting_rsp>
[0x6daa] Extending timeout for 0x1d request
[0x6daa:1:0x0001]: reporting 'battery_percentage_remaining' attr on 'power' cluster: 3600/10800/1: Result: '[[ConfigureReportingResponseRecord(status=0)]]'
[0x6daa:1:0x0001]: finished channel configuration
[0x6daa] Extending timeout for 0x1f request
[0x6daa:1:0x0005]: bound 'scenes' cluster: Status.SUCCESS
[0x6daa:1:0x0005]: finished channel configuration
[0x6daa:1:0x0008]: initializing channel: from_cache: False
[0x6daa:1:0x0006]: initializing channel: from_cache: False
[0x6daa:1:0x0020]: 'async_configure' stage succeeded
[0x6daa:1:0x1000]: 'async_configure' stage succeeded
[0x6daa:1:0x0000]: 'async_configure' stage succeeded
[0x6daa:1:0x0001]: 'async_configure' stage succeeded
[0x6daa:1:0x0008]: 'async_configure' stage succeeded
[0x6daa:1:0x0006]: 'async_configure' stage succeeded
[0x6daa:1:0x0019]: 'async_configure' stage succeeded
[0x6daa:1:0x0005]: 'async_configure' stage succeeded
[0x6daa:1:0x0019]: initializing channel: from_cache: False
[0x6daa:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=29 command_id=Command.Read_Attributes_rsp>
[0x6daa:1:0x0005]: initializing channel: from_cache: False
[0x6daa](TRADFRI remote control): completed configuration
[0x6daa](TRADFRI remote control): stored in registry: ZhaDeviceEntry(name='IKEA of Sweden TRADFRI remote control', ieee='00:0d:6f:ff:fe:11:b4:06', last_seen=1608462360.5794895)
[0x6daa] Extending timeout for 0x21 request
[0x6daa:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=31 command_id=Command.Read_Attributes_rsp>
[0x6daa:1:0x0000]: initializing channel: from_cache: False
[0x6daa:1:0x0020]: 'async_initialize' stage succeeded
[0x6daa:1:0x1000]: 'async_initialize' stage succeeded
[0x6daa:1:0x0000]: 'async_initialize' stage succeeded
[0x6daa:1:0x0001]: 'async_initialize' stage succeeded
[0x6daa:1:0x0008]: 'async_initialize' stage succeeded
[0x6daa:1:0x0006]: 'async_initialize' stage succeeded
[0x6daa:1:0x0019]: 'async_initialize' stage succeeded
[0x6daa:1:0x0005]: 'async_initialize' stage succeeded
[0x6daa](TRADFRI remote control): power source: Battery or Unknown
[0x6daa](TRADFRI remote control): completed initialization
[0x6daa:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=33 command_id=Command.Default_Response>
[0x6daa:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: [64, <Status.SUCCESS: 0>]
[0x6daa](TRADFRI remote control): started initialization
[0x6daa:ZDO](TRADFRI remote control): 'async_initialize' stage succeeded
[0x6daa:1:0x0020]: initializing channel: from_cache: False
[0x6daa:1:0x1000]: initializing channel: from_cache: False
[0x6daa] Extending timeout for 0x23 request
[0x6daa] Extending timeout for 0x25 request
[0x6daa:1:0x0008]: initializing channel: from_cache: False
[0x6daa:1:0x0006]: initializing channel: from_cache: False
[0x6daa:1:0x0019]: initializing channel: from_cache: False
[0x6daa:1:0x0005]: initializing channel: from_cache: False
[0x6daa:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=35 command_id=Command.Read_Attributes_rsp>
[0x6daa:1:0x0000]: initializing channel: from_cache: False
[0x6daa:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=37 command_id=Command.Read_Attributes_rsp>
[0x6daa:1:0x0020]: 'async_initialize' stage succeeded
[0x6daa:1:0x1000]: 'async_initialize' stage succeeded
[0x6daa:1:0x0000]: 'async_initialize' stage succeeded
[0x6daa:1:0x0001]: 'async_initialize' stage succeeded
[0x6daa:1:0x0008]: 'async_initialize' stage succeeded
[0x6daa:1:0x0006]: 'async_initialize' stage succeeded
[0x6daa:1:0x0019]: 'async_initialize' stage succeeded
[0x6daa:1:0x0005]: 'async_initialize' stage succeeded
[0x6daa](TRADFRI remote control): power source: Battery or Unknown
[0x6daa](TRADFRI remote control): completed initialization
[0x6daa:zdo] ZDO request ZDOCmd.Match_Desc_req: [0xFFFD, 260, [25], []]
[0x6daa:1:0x0019] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=4 command_id=1>
[0x6daa:1:0x0019] ZCL request 0x0001: [1, 4476, 4545, 587286065, 1]
[0x6daa:1:0x0019] OTA query_next_image handler for 'IKEA of Sweden TRADFRI remote control': field_control=1, manufacture_id=4476, image_type=4545, current_file_version=587286065, hardware_version=1
[0x6daa:1:0x0019] No OTA image is available

ygreq commented 3 years ago

BTW, now that I changed the battery and paired the device again, everything works ok like I said. And I took the battery out, leaved it out for a minute and put it back in and the device still works. I don't have to pair again.

Adminiuga commented 3 years ago

I'm not saying that's ok. I'm just saying that I did not see anything specific in the logs, but maybe because bit did not happen then.

The fact that you need to re-pair the device after you change the batteries hint that device either left the network or lost connection that the network. Now, silabs in embery 6.9.0.0! release notes mentioned a fixed bug where a battery powered device, fails to enter the sleep to preserve the battery when it looses connection to the network and fails to reconnect. This looks very similar.to your situation, but i don't know when the bug was introduced.

How many routers do you have in the network?

At this moment I don't know how to help. I don't believe it is a bug with zha per se, as i would expect to see more reports like that. I have a few Ikea remotes, and while one is showing blow battery, it still works and it defy lasted more that two weeks.

rodvdb commented 3 years ago

I have had the same issue with 2 of these IKEA 5 button remotes. Each had been happy on zigbee2mqtt with a cc2531 for 6+ months. Moved the whole network over to zha with a sonoff ZigBee bridge and both batteries emptied in a day... Replaced both batteries and empty again within 24h. Each time the battery is flat the switch needs to be re-paired to the network so that seems to be consistent with the other reports.

Had to move them back to z2m because I need them to work. They have been happy on z2m again now for about a week with new batteries.

I have a third e1810 still in its box which I will connect to zha and try to collect some logs (I might need to buy some more packs of batteries too..)

Running home assistant core 2020.12 ZigBee bridge is running tasmota 9.1.0 with ZigBee fw 6.7.6

Happy to try anything else to diagnose.

Thanks

dmulcahey commented 3 years ago

This sounds exactly like that EZSP stack bug. This will likely need a new firmware on the bridge. The reason z2m would be unaffected is that you are using a TI stack there vs SI stack on ZHA.

Adminiuga commented 3 years ago

I can say definitively 5-button remotes were for quite a while in ZHA and this is the 1st report of it eating batteries. In both reported cases the common factor is the Sonof bridge. Either firmware or wifi connection to the bridge is the problem. I really wish they had an ethernet connection. And I cannot recommend running ZHA over wifi serial connection.

rodvdb commented 3 years ago

Thanks for the responses. Shame, looks like there are issues updating the zbbridge to emberznet 6.8 and 6.9 at the moment but that is a tasmota issue rather than zha.

Reason for using zbbridge is that it is cheap and cc2531 was running out of steam with more devices on the network. Other than the IKEA switches zha is working very nicely with it...

ygreq commented 3 years ago

The fact that you need to re-pair the device after you change the batteries hint that device either left the network or lost connection that the network.

Yes. But like I said, it only happens to devices that finish their batteries.

These are the situations:

I put a new battery onto a device and it finishes the battery fast. I change the battery and it does not get back on the zigbee network. I have to re-pair after changing the battery in order for the device to be on the network again
After re-pairing the device I had problems with and everything working fine, I take the battery out as a test and after a while I put it back in. Everything is working normally. I do not have to re-pair again
I have a device that is working fine. I take the battery out, I put it back in. Everything is working fine. I do not have to re-pair again

It is very weird for me to see that I need to re-pair it only in the first situation presented above. Any help here?

MattWestb commented 3 years ago

I have 2 E1743 that steering under cabin GX53 in my kitchen and also 3x GU10 WS with the 5 button in the sealing. The last is still running after 18 months the first E2743 was emptying the battery after around 12 months and was compleet empty and was needed repairing with the IKEA GW. The second E1743 i was seeing it was blinking red in the evening then using it and changing battery and was not needed repairing it. And some users on reddit have reporting its needed repairing after complete battery drain also with the IKEA GW.

So its not only ZHA that having the problem and Tasmota have disabling battery reporting for IKEA remotes then its draining the batteries (I think its not the cause of the draining).

Then all IKEA controlling devices (exception the old motion sensor) is Zigbee 3 its need updating the security fram counter for all transactions that is made (I think its moderate for ZLL 2) = writing the NVR data in the flash. If the battery is to low it can being that the flash is not correct written / erased and ending up with corrupted NVR flash = also network parameters is damaged and the device cant rejoining the network without resetting the device for recreating the NVR in it and repairing it.

As Adminiuga was saying its one nasty bug in the stack but its more than one bug that is being found that making problems with sleeping end devices then reading the last EZSP release notes.

Im pretty sure if triggering the bug the device is draining the batter and if not then its working well and its not depending of the coordinator only if the bug is triggered in the device or on.

Adminiuga commented 3 years ago

It is very weird for me to see that I need to re-pair it only in the first situation presented above. Any help here?

Did you read https://github.com/home-assistant/core/issues/43969#issuecomment-748610549 ?

Device looses connection to the network, fails to reconnect -> drains the battery. If device is not connected to the network, a new battery won't connect it either

ygreq commented 3 years ago

@Adminiuga I did not understand that but I do now. Thank you for taking your time to look into this.

I am still checking, but I believe that only some ikea switches and remotes do this and others don't eventhough they are the same model.

@MattWestb, thank you for your input. From what I understand there is a problem with the ikea devices. I will try to switch to other companies' products in this case.

Thank you all!

Mariusthvdb commented 3 years ago

just as a followup on my earlier contribution: Today I especially installed the Conbee II stick and was hoping the Ikea motion sensor (older model) would behave better. Using the Deconz Phoscon integration and add-on. Unfortunately, only after about 6 hours, the batteries (which were new high quality ones) are down to 21 %....

Seems not a very viable solution just yet either. Or, must be an issue with the sensor itself? No way to test I am afraid?

Adminiuga commented 3 years ago

Two different integrations using different hardware yet same result point to a faulty sensor

MattWestb commented 3 years ago

Its not only IKEA products that being hitted of the bug, many other manufacturers is using the same chips and have the same problem but its not reported. And one more problem is that all systems have different god and bad things like Xiaomi that is have done mutch strange things that can being done or OSRAM that was doing it right but in one wrong way.

The problem can being triggered in IKEA devices and many other but its not so likely its happens. IKEA have delivered many thousands of them and not so oft is the bug being triggered.

@Mariusthvdb I have 2 old and 2 new one. One of each is still on original batteries on my IKEA GW and the other 2 was on deCONZ until late summer and was used mutch for testing bellows and the original batteries was out after one and a half years. (the old was false triggering then battery was going low). So my conclusion is if the bug is being triggered the batteries is empty very fast and if not they is lasting long and its not so likely its being triggered but its happenings.

What was the voltages of the cells before putting then on the motion sensor ? If good quality and french one it should being over 3.3V and its going down to 79% in some hours you have one more or less short circuit in the sensor or very bad batteries.

By the way the old motion sensor is the only one lightlink controlling device that not have getting zigbee 3 update from IKEA :-((

Mariusthvdb commented 3 years ago

silly enough, I only have 1 modern device, and all my other devices are the older model. Of these, only the one I report on here is depleting this fast... 16% now within half a day.

So maybe it still is something else.

MattWestb commented 3 years ago

The IKEA sensors is not reporting battery very frequently but you is getting status updates so its working. As Adminiuga was saying its being broken or the batteries is bad from the factory or its have getting one real christmas orgy and eating all your batteries i can.

Then you is changing battery next time (must being in some days then its being zero power left) can you measure the voltage of the "old" and new one before putting them in ?

ygreq commented 3 years ago

Two different integrations using different hardware yet same result point to a faulty sensor

Personally I did not have these problems with the Ikea Tradfri Gateway. But for sure if the battery depletes again on the device I am tracking, I will add it to the Tradfri Gateway again and see what happens afterwards. The update will take same time, I believe, but still.

MattWestb commented 3 years ago

@Adminiuga My 5 button remote was not reporting in 24 h so i have resetting it 4 times and repairing it and binding it to one groupe but it was not helping. 2 of my 2 button remotes was doing the same and also not helping resetting anc binding to their groupe (from reading the last seen in ZHA network card). Was comparing the poll control cluster (0x0020) attribute config with the others not resetted ones. Its looks being incomplete after resetting the device and binding it to one groupe. Was reading that the poll control attribute should being made after the endpoints cluster being bond to one groue / device (NXP docks). So was sending regonfigure device and waking it up and its start reporting and being registered in last seen in ZHA network card. Perhaps is it necessary doing one reconfigure device after doing one new binding of IKEA controlling devices ? One more interesting thing with the hand made groups with only one IKEA outlet. After reconfigure the controlling device that is bonded to the group the coordinator was added.

2020-12-27 12:00:03 INFO (MainThread) [homeassistant.components.zha.core.group] [Plugg Küche](0x0006): group_member_added - endpoint: <bellows.zigbee.application.EZSPCoordinator.EZSPEndpoint object at 0x6cc527d8

That was not being done before on HA restart that was little strange than the groups is being setted up on start of ZHA.

Should looking if the battery problems can being connected to the false configured attribute reporting of the controlling devices.

nmsoares commented 3 years ago

Hi all. Just like to say that I too am experiencing the same issues.

Baterry drain in IKEA Tradfri switches
Need to pair the devices after new battery

In my case, the new batteries (+/-3,3v measured from packaged) lasted 2 days without almost no activity (button presses, etc)

I'm using ZHA with a Sonoff Bridge flashed with Tasmota (ver 9.2).

How can I help you guys with the debugging? Where can I grab the debugging logs from ZHA ? Thanks in advance

Adminiuga commented 3 years ago

Start by eliminating Sonoff bridge. But you would need a different stick to replace sonoff.

nmsoares commented 3 years ago

Why ? Not any good ?

MattWestb commented 3 years ago

I can being that Sonoff have one EFR32 2 gen that making some problems but its not sure. Other open zigbee systems have seen the same problems and its looks like most times the batteries is lasting for over one year and sometime its being empty very fast (I was returning one to IKEA after the first lockdown because it was eating batteries 4 times in 1.5 months).

Silabs have some nasty bugs that can being triggered that is making the flash not getting in sleep mode and making the battery being killed and very likely also doing the repairing problems.

Do use good batteries that is not being old / outdated and have over 3V voltage. If the battery is being fast drained its very likely need repairing if its going down to fare.

For them moment I have some that is still on original battery after nearly 2 years and some i changed after some months and unusual some weeks but changing battery and is normally working but not always.

One more thing trying paring the remotes with one router that is good / near the finale position of it so it have good signal and not need using high power for communicating and changing parent then losing connectivity.

As its sad its dot getting any 110% answer for the problems only different experience so its little try and error game here for the moment.

Shellfishgene commented 3 years ago

Just wanted to note I also have the same problem, using the Ikea E1743 on/off remote. I moved 2 of them from the Ikea hub to ZHA with the Sonoff bridge and fresh (Ikea) batteries drain within 1 or 2 weeks despite being used only once a day or so. The batteries on the remotes that are still on the Ikea hub last for months now.

Adminiuga commented 3 years ago

@Shellfishgene post the device firmware Id as reported by zha. Does you remote also has to be rejoined manually after the depleted battery is replaced?

At this point a common factor in all these reports is the sonoff bridge. Could be firmware on the bridge, could be unstable wifi connection knocking off serial over WiFi. Do any other Zigbee device work 24/7?

MattWestb commented 3 years ago

ER32 second gen NCPs ??

Mariusthvdb commented 3 years ago

Not really sure it is of any use trying to find the issue in 3D party hardware. My faulty motion sensor was depleted in less than 2 days on Conbee II so I renewed the batteries and added it back to the original IKEA Hub. Brand New quality Duracells. After pairing they showed up at 87% ..... after adding to Lovelace, so 2 minutes later at the most, is was on 71. Right now, couple of hours on, it's on 34.

This must be the individual sensor, because all others do fine. Don't think it has anything to do with other integrations or hub devices... It's cheaper buying a new one, than changing batteries ;-((

home-assistant / core