TP-Link EP25 with Hardware 2.6 and new Firmware 1.0.3 stops working

richie510 commented 4 months ago

The problem

The new firmware results in the inability to connect, and a constant "reconfigure' popup reoccurs.

One of my devices updated the firmware overnight, and then HAOS was complaining about the device this morning. When I went poking around in the Kasa app, I also updated the firmware on my other EP25 and it immediately got the same problem after updating to the 1.0.3 firmware.

What version of Home Assistant Core has the issue?

2024.7.2

What was the last working version of Home Assistant Core?

2024.7.2

What type of installation are you running?

Home Assistant OS

Integration causing the issue

TP-Link Kasa

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant.components.tplink.coordinator
Source: helpers/update_coordinator.py:365
integration: TP-Link Smart Home (documentation, issues)
First occurred: 8:22:41 AM (1 occurrences)
Last logged: 8:22:41 AM

Authentication failed while fetching 10.20.48.26 data: Error sending secure_passthrough message: 10.20.48.26: TRANSPORT_UNKNOWN_CREDENTIALS_ERROR(1003) (error_code=TRANSPORT_UNKNOWN_CREDENTIALS_ERROR)

Additional information

No response

home-assistant[bot] commented 4 months ago

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

Code owner commands

Code owners of `tplink` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign tplink` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

_{^{(message by CodeOwnersMention)}}

tplink documentation tplink source _{^{(message by IssueLinks)}}

richie510 commented 4 months ago

I also documented the issue here: https://github.com/python-kasa/python-kasa/issues/1065

sdb9696 commented 4 months ago

The settings in HA should automatically update for the device to pickup the new authentication method. Could you enable debug logging and upload some HA core logs from the restart and for 20 minutes after that?

richie510 commented 4 months ago

@sdb9696 I enabled debug logging on the TPLink integration, restarted HA and then waited some time before disabling the debug logging. That generated a 12MB log file. Is it safe to paste that whole log here? Should I just be looking for interesting things related to TPLink in there?

sdb9696 commented 4 months ago

It does contain some sensitive info like location and MAC addresses. You can edit the log and redact that info you prefer and also you can hmu on discord (sdb9696) and share via google drive or similar if you prefer not to have it on GitHub.

richie510 commented 4 months ago

I'm terrible at Discord. Gave up and just putting the file here. home-assistant_tplink_2024-07-15T17-50-14.685Z.log

richie510 commented 4 months ago

I also want to comment that it appears that the integration is now working, but it is still nagging some messages in notifications and settings about the integration needing reconfiguration.

cmgrayb commented 4 months ago

Can confirm, this issue has been plaguing me as well. The only reliable workaround I've found is to re-enter the credentials, wait for it to give the above error, restart HA (integration reload does not fix it), and then enter the credentials again. None of them have bothered me a second time when doing that.

Eric2XU commented 4 months ago

I am having this issue too. However after entering the username and password 5 times (for my 5 units) then restarting HA and doing it again does not fix it.

Happy to provide any logs or do any actions if required. I am kicking myself for allowing auto update of the firmware.

sdb9696 commented 4 months ago

@richie510 from your logs it looks like it is working. There are other errors in the logs relating to your custom integrations so that could be why you're seeing other nagging messages.

@Eric2XU if you could upload some logs running from a restart that would be helpful thanks.

richie510 commented 4 months ago

@sdb9696 as I mentioned yesterday, it did seem to start working even though the TP-link integration still seemed to be nagging me. Today I restarted home assistant one more time and there are no more error messages and no more requests to enter credentials and the TP Link integration is still working.

So I guess the system finally figured out what it needed or the EP25 started to behave better after chilling out for a bit.

If requested, I can enable debug logging and pull an unused EP25 out of the closet, connect it to HA and then upgrade the FW to see if I can capture what all the trouble was about... Let me know.

Eric2XU commented 4 months ago

Pre-Debug Logging I got this:

2024-07-16 13:40:53.167 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Kitchen Over Cabinet 1 EP25' for tplink integration could not authenticate: Unable to complete handshake: 172.16.0.125:

After turning on debugging I got alot:

'2024-07-16 14:05:07.720 DEBUG (MainThread) [kasa.aestransport] Created AES transport for 172.16.0.125 2024-07-16 14:05:07.720 DEBUG (MainThread) [kasa.device] Initializing 172.16.0.125 of type <class 'kasa.smart.smartdevice.SmartDevice'> 2024-07-16 14:05:07.721 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953201280356352,"request_time_milis":1721153107721,"terminal_uuid":"faCZQMT6cQZHUOJrgrWJjA=="}' 2024-07-16 14:05:07.721 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app 2024-07-16 14:05:07.909 DEBUG (MainThread) [kasa.smartprotocol] Unable to authenticate with 172.16.0.125, not retrying 2024-07-16 14:05:07.909 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Kitchen Over Cabinet 1 EP25' for tplink integration could not authenticate: Unable to complete handshake: 172.16.0.125: TRANSPORT_UNKNOWN_CREDENTIALS_ERROR(1003) (error_code=TRANSPORT_UNKNOWN_CREDENTIALS_ERROR) 2024-07-16 14:05:54.141 DEBUG (MainThread) [kasa.aestransport] Created AES transport for 172.16.0.125 2024-07-16 14:05:54.141 DEBUG (MainThread) [kasa.device] Initializing 172.16.0.125 of type <class 'kasa.smart.smartdevice.SmartDevice'> 2024-07-16 14:05:54.142 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953395984142336,"request_time_milis":1721153154142,"terminal_uuid":"qI4MMTpg4OEUcLRRVSi+kg=="}' 2024-07-16 14:05:54.142 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app 2024-07-16 14:05:54.183 DEBUG (MainThread) [kasa.smartprotocol] Unable to authenticate with 172.16.0.125, not retrying 2024-07-16 14:05:54.183 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Kitchen Over Cabinet 1 EP25' for tplink integration could not authenticate: Unable to complete handshake: 172.16.0.125: TRANSPORT_UNKNOWN_CREDENTIALS_ERROR(1003) (error_code=TRANSPORT_UNKNOWN_CREDENTIALS_ERROR) 2024-07-16 14:07:56.138 DEBUG (MainThread) [kasa.discover] [DISCOVERY] 172.16.0.125 >> {'system': {'get_sysinfo': None}} 2024-07-16 14:07:56.148 DEBUG (MainThread) [kasa.klaptransport] Created KLAP transport for 172.16.0.125 2024-07-16 14:07:56.148 DEBUG (MainThread) [kasa.discover] [DISCOVERY] 172.16.0.125 << {'result': {'device_id': 'xxxxx', 'owner': 'xxxxxxxx', 'device_type': 'SMART.KASAPLUG', 'device_model': 'EP25(US)', 'ip': '172.16.0.125', 'mac': 'E4-FA-C4-xx-xx-xx', 'is_support_iot_cloud': True, 'obd_src': 'apple', 'protocol_version': 1, 'factory_default': False, 'mgt_encrypt_schm': {'is_support_https': False, 'encrypt_type': 'KLAP', 'http_port': 80, 'lv': 2}}, 'error_code': 0} 2024-07-16 14:07:56.149 DEBUG (MainThread) [kasa.device] Initializing 172.16.0.125 of type <class 'kasa.smart.smartdevice.SmartDevice'> 2024-07-16 14:07:56.152 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953907731173376,"request_time_milis":1721153276152,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="}' 2024-07-16 14:07:56.152 DEBUG (MainThread) [kasa.klaptransport] Starting handshake with 172.16.0.125 2024-07-16 14:07:56.152 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app/handshake1 2024-07-16 14:07:56.174 DEBUG (MainThread) [kasa.klaptransport] Handshake1 posted at 2024-07-16 14:07:56.174450. Host is 172.16.0.125, Responsestatus is 200, Request was d8cbaa15abc4992c0d9158a6a6cefb94 2024-07-16 14:07:56.174 DEBUG (MainThread) [kasa.klaptransport] Handshake1 success at 2024-07-16 14:07:56.174737. Host is 172.16.0.125, Server remote_seed is: 61244a81351e48810f34488025294980, server hash is: 97262452a0196c946886b95f7b85b1dd2ad063d5eeaa54d2c90af68757c18f77 2024-07-16 14:07:56.175 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app/handshake2 2024-07-16 14:07:56.188 DEBUG (MainThread) [kasa.klaptransport] Handshake2 posted 2024-07-16 14:07:56.188772. Host is 172.16.0.125, Response status is 200, Request was 65d41736fa2e51718ef7602087f54d59b1721c8d09af87e63094f91966580a05 2024-07-16 14:07:56.189 DEBUG (MainThread) [kasa.klaptransport] Handshake with 172.16.0.125 complete 2024-07-16 14:07:56.190 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app/request 2024-07-16 14:07:56.278 DEBUG (MainThread) [kasa.klaptransport] Query posted Host is 172.16.0.125, Sequence is 166660428, Response status is 200, Request was {"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953907731173376,"request_time_milis":1721153276152,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="} 2024-07-16 14:07:56.288 DEBUG (MainThread) [kasa.klaptransport] 172.16.0.125 << {'error_code': 0, 'ip': '172.16.0.125', 2024-07-16 14:07:56.297 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 << {'error_code': 0, 'ip': '172.16.0.125', 2024-07-16 14:07:56.301 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"get_auto_off_config","params":{"start_index":0}},{"method":"get_connect_cloud_state","params":null},{"method":"get_device_info","params":null},{"method":"get_device_usage","params":null},{"method":"get_energy_usage","params":null}]},"requestID":1262953908360318976,"request_time_milis":1721153276302,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="}' 2024-07-16 14:07:56.303 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app/request 2024-07-16 14:07:56.416 DEBUG (MainThread) [kasa.klaptransport] Query posted Host is 172.16.0.125, Sequence is 166660429, Response status is 200, Request was {"method":"multipleRequest","params":{"requests":[{"method":"get_auto_off_config","params":{"start_index":0}},{"method":"get_connect_cloud_state","params":null},{"method":"get_device_info","params":null},{"method":"get_device_usage","params":null},{"method":"get_energy_usage","params":null}]},"requestID":1262953908360318976,"request_time_milis":1721153276302,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="} 2024-07-16 14:07:56.424 DEBUG (MainThread) [kasa.klaptransport] 172.16.0.125 << {'error_code': 0, 'ip': '172.16.0.125', 2024-07-16 14:07:56.429 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 << {'error_code': 0, 'ip': '172.16.0.125', 2024-07-16 14:07:56.430 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-6 >> '{"method":"multipleRequest","params":{"requests":[{"method":"get_current_power","params":null},{"method":"get_latest_fw","params":null},{"method":"get_auto_update_info","params":null},{"method":"get_led_info","params":{"led_rule":null}},{"method":"get_device_time","params":null}]},"requestID":1262953908897189888,"request_time_milis":1721153276430,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="}' 2024-07-16 14:07:56.430 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app/request 2024-07-16 14:07:56.527 DEBUG (MainThread) [kasa.klaptransport] Query posted Host is 172.16.0.125, Sequence is 166660430, Response status is 200, Request was {"method":"multipleRequest","params":{"requests":[{"method":"get_current_power","params":null},{"method":"get_latest_fw","params":null},{"method":"get_auto_update_info","params":null},{"method":"get_led_info","params":{"led_rule":null}},{"method":"get_device_time","params":null}]},"requestID":1262953908897189888,"request_time_milis":1721153276430,"terminal_uuid":"93jBbrDi1S1rd05LIQAg1Q=="} 2024-07-16 14:07:56.532 DEBUG (MainThread) [kasa.klaptransport] 172.16.0.125 << {'error_code': 0, 2024-07-16 14:07:56.535 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-6 << {'error_code': 0, 2024-07-16 14:07:56.535 DEBUG (MainThread) [kasa.smart.smartdevice] Got an update: {'get_auto_off_config': {'enable': False, 'delay_min': 120}, 'get_connect_cloud_state': {'status': 0}, 'get_device_info': {'device_id': 'xxxxxxxxxx', 'fw_ver': '1.0.3 Build 240529 Rel.145252', 'hw_ver': '2.6', 'type': 'SMART.KASAPLUG', 'model': 'EP25', 'mac': 'E4-FA-C4-xx-xx-xx, 'hw_id': 'xxxxxxx', 'fw_id': '00000000000000000000000000000000', 'oem_id': 'xxxxx', 'ip': '172.16.0.125', 'time_diff': -300, 'ssid': 'xxxx==', 'rssi': -50, 'signal_level': 2, 'auto_off_status': 'off', 'auto_off_remain_time': 0, 'longitude': -xxxxx, 'latitude': xxxx, 'lang': 'en_US', 'avatar': 'wall_lamp', 'region': 'America/New_York', 'specs': '', 'nickname': 'xxxxxxxxx==', 'has_set_location_info': True, 'device_on': True, 'on_time': 27834, 'default_states': {'type': 'last_states', 'state': {}}, 'overheat_status': 'normal', 'power_protection_status': 'normal', 'overcurrent_status': 'normal'}, 'get_device_usage': {'time_usage': {'today': 463, 'past7': 3805, 'past30': 15223}, 'power_usage': {'today': 83, 'past7': 679, 'past30': 2721}, 'saved_power': {'today': 380, 'past7': 3126, 'past30': 12502}}, 'get_energy_usage': {'today_runtime': 463, 'month_runtime': 8631, 'today_energy': 83, 'month_energy': 1542, 'local_time': '2024-07-16 14:07:55', 'electricity_charge': [0, 0, 24], 'current_power': 10705}, 'get_current_power': {'current_power': 10}, 'get_latest_fw': {'type': 0, 'fw_ver': '1.0.3 Build 240529 Rel.145252', 'release_date': '', 'release_note': '', 'fw_size': 0, 'hw_id': '', 'oem_id': '', 'need_to_upgrade': False}, 'get_auto_update_info': {'enable': True, 'time': 180, 'random_range': 120}, 'get_led_info': {'night_mode': {'night_mode_type': 'sunrise_sunset', 'start_time': 1220, 'end_time': 326, 'sunrise_offset': 0, 'sunset_offset': 0}, 'led_status': True, 'led_rule': 'always', 'bri_config': {'bri_type': 'overall', 'overall_bri': 50}}, 'get_device_time': {'time_diff': -300, 'timestamp': 1721153275, 'region': 'America/New_York'}} 2024-07-16 14:07:56.542 DEBUG (MainThread) [kasa.aestransport] Created AES transport for 172.16.0.125 2024-07-16 14:07:56.543 DEBUG (MainThread) [kasa.device] Initializing 172.16.0.125 of type <class 'kasa.smart.smartdevice.SmartDevice'> 2024-07-16 14:07:56.543 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953909371146240,"request_time_milis":1721153276543,"terminal_uuid":"xtlGxmCuzTbg6OGr5n7xgQ=="}' 2024-07-16 14:07:56.543 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app 2024-07-16 14:07:56.575 DEBUG (MainThread) [kasa.smartprotocol] Unable to authenticate with 172.16.0.125, not retrying 2024-07-16 14:07:56.575 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Kitchen Over Cabinet 1 EP25' for tplink integration could not authenticate: Unable to complete handshake: 172.16.0.125: TRANSPORT_UNKNOWN_CREDENTIALS_ERROR(1003) (error_code=TRANSPORT_UNKNOWN_CREDENTIALS_ERROR) 2024-07-16 14:07:56.576 DEBUG (MainThread) [kasa.aestransport] Created AES transport for 172.16.0.125 2024-07-16 14:07:56.576 DEBUG (MainThread) [kasa.device] Initializing 172.16.0.125 of type <class 'kasa.smart.smartdevice.SmartDevice'> 2024-07-16 14:07:56.577 DEBUG (MainThread) [kasa.smartprotocol] 172.16.0.125 multi-request-batch-1 >> '{"method":"multipleRequest","params":{"requests":[{"method":"component_nego","params":null},{"method":"get_device_info","params":null},{"method":"get_connect_cloud_state","params":null}]},"requestID":1262953909513752576,"request_time_milis":1721153276577,"terminal_uuid":"OQvHgYNp4coUCOS4iQx4dw=="}' 2024-07-16 14:07:56.577 DEBUG (MainThread) [kasa.httpclient] Posting to http://172.16.0.125:80/app 2024-07-16 14:07:56.601 DEBUG (MainThread) [kasa.smartprotocol] Unable to authenticate with 172.16.0.125, not retrying 2024-07-16 14:07:56.601 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Kitchen Over Cabinet 1 EP25' for tplink integration could not authenticate: Unable to complete handshake: 172.16.0.125: TRANSPORT_UNKNOWN_CREDENTIALS_ERROR(1003) (error_code=TRANSPORT_UNKNOWN_CREDENTIALS_ERROR)'

I will mention I have 5 of these things, the one thing I havent tried is to remove them and add them again if you thought that would fix it?

sdb9696 commented 4 months ago

@Eric2XU have you power cycled the devices?

Eric2XU commented 4 months ago

@Eric2XU have you power cycled the devices?

I have. I run as a docker container. I went so far as to delete the image and bring down the 2024.7.2.

I also rebooted the hardware and gave it a shot of OS updates in the process. I have restarted the container as well.

sdb9696 commented 4 months ago

I mean the power cycle the TPLink devices rather than HA.

If so it might be easier to hook up on discord and debug there. My handle is sdb9696 but not around now until tomorrow.

Eric2XU commented 4 months ago

I am working with sbd9696 but I can say that for me, deleting the devices and adding them again (possibly in conjunction with upgrading to 2024.7) did fix the issue. I intentionally didnt fix one of the 5 devices I have and am now working with sdb9696 on discord to troubleshoot to see if we can figure out why it happens. But figured I would pass along a hint to anyone else having a issue in the meantime

sdb9696 commented 4 months ago

@richie510, out of interest are you using vlans/firewalls at all in your network setup?

richie510 commented 4 months ago

@richie510, out of interest are you using vlans/firewalls at all in your network setup?

I am not.

sdb9696 commented 4 months ago

This issue will be closed by #122089 due for release this Friday. The discovery broadcast normally updates the devices to the new firmware protocols. In some instances that doesn't work, e.g. vlans/firewalls/other.

Many thanks @Eric2XU for your help testing this 💪 🚀

home-assistant / core