LCN Integration not adding new entities

nordmanntanne commented 2 years ago

The problem

After i add a new LCN entity in configuration.yaml and restart the entity ist not added to the database so that i can use it in ha. The existing lcn entities are working fine. Changing names from existing entrys are not applied. The existing lcn entities are working fine. I still can control them i.e. over lovelance

What version of Home Assistant Core has the issue?

core-2021.11.5

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Core

Integration causing the issue

lcn

Link to integration documentation on our website

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

Example YAML snippet

name: Carport Steckdosen 
      address: myhome.s0.m82
      output: relay7

Anything in the logs that might be useful for us?

No response

Additional information

No response

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

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

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

Hey there @alengwenus, mind taking a look at this issue as it has been labeled with an integration (lcn) you are listed as a code owner for? Thanks! _{^{(message by CodeOwnersMention)}}

alengwenus commented 2 years ago

The indentation of your example is wrong. Please ensure that this isn't an issue in your configuration.yaml.

You could also try to remove the whole LCN integration in the integration list of the Hass frontend (Configuration -> Integrations). After a restart the LCN integration will be all new imported from your configuration.yaml. Maybe this helps?

nordmanntanne commented 2 years ago

I seperated lcn config in several files with i.e. switches: !include lcn_switches.yaml. Thats the reason why the indentation looks wrong. The config works for years. Today i tried to bring the config in configuration.yaml together without seperating. No change. I tried to delete the integration. But after restart the lcn integration is not importing anything. In the logs i see "Connection to PCHK "myhome" failed". The ip and login data are still correct. My PKE is reachable. Restarting PKE does not solve the issue.

alengwenus commented 2 years ago

Sound like some sort of connection issues. Could you please add the following code to your configuration.yaml and restart HA. If the output does not help you, please post the logs here.

logger:
  default: error
  logs:
    homeassistant.components.lcn: debug
    pypck: debug

nordmanntanne commented 2 years ago

Thank you for your help! In the logs now i see:

2021-11-28 10:05:50 DEBUG (MainThread) [homeassistant.components.lcn.config_flow] Validating connection parameters to PCHK host 'myhome' 2021-11-28 10:05:51 DEBUG (MainThread) [pypck.connection] PCHK server connected at 192.168.100.129:4114 2021-11-28 10:05:51 DEBUG (MainThread) [pypck.connection] from PCHK: LCN-PCK/IP 1.0 2021-11-28 10:05:51 DEBUG (MainThread) [pypck.connection] from PCHK: Username: 2021-11-28 10:05:51 DEBUG (MainThread) [pypck.connection] to PCHK: XXXXX 2021-11-28 10:05:53 DEBUG (MainThread) [pypck.connection] from PCHK: Password: 2021-11-28 10:05:53 DEBUG (MainThread) [pypck.connection] to PCHK: XXXXX 2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] from PCHK: OK 2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] PCHK authorization successful! 2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] to PCHK: !CHD 2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] from PCHK: $io:#LCN:connected 2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] PCHK: LCN is connected. 2021-11-28 10:06:06 WARNING (MainThread) [homeassistant.components.lcn.config_flow] Connection to PCHK "myhome" failed

nordmanntanne commented 2 years ago

2021-11-28 10:06:06 DEBUG (MainThread) [pypck.connection] from PCHK: (dec-mode) 2021-11-28 10:06:06 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved

alengwenus commented 2 years ago

That's strange... It looks like that the response time from your PKE during authentification (username/password exchange) is extremely long (~15s). That should be in the range of a few ms. The result is that the LCN integration runs into a timeout error which marks the connection as failed. I don't have an idea what's the reason for this. Do you notice the same time delay when connection with LCN Pro or any other software (e.g. Telnet at port 4114)?

nordmanntanne commented 2 years ago

Tried both telnet has absolutely no delay. After login i see messsages from several modules. LCN-Pro also no issues. It is running as mentioned. I am confused that the error message "connection failed" occurs after the message "lcn is connected".

nordmanntanne commented 2 years ago

Downgraded to 2021.9.1 and i am not having any issues. I can add new entities and can control them. Everything is working as expected. But in the log i see:

2021-11-28 14:38:10 DEBUG (MainThread) [homeassistant.components.lcn.config_flow] Validating connection parameters to PCHK host 'myhome' 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] PCHK server connected at 192.168.100.129:4114 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] from PCHK: LCN-PCK/IP 1.0 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] from PCHK: Username: 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] to PCHK: xxx 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] from PCHK: Password: 2021-11-28 14:38:12 DEBUG (MainThread) [pypck.connection] to PCHK: xxx 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: OK 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] PCHK authorization successful! 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] to PCHK: !CHD 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: $io:#LCN:connected 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] PCHK: LCN is connected. 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000031Rx000 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000031Rx002 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000031S1025 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000011S2050 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000021Rx136 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000011Rx002 2021-11-28 14:38:24 DEBUG (MainThread) [pypck.connection] from PCHK: :M000031Rx002 2021-11-28 14:38:25 WARNING (MainThread) [homeassistant.components.lcn.config_flow] Connection to PCHK "myhome" failed 2021-11-28 14:38:26 DEBUG (MainThread) [pypck.connection] from PCHK: (dec-mode) 2021-11-28 14:38:26 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/pypck/connection.py", line 127, in read_data_loop await self.process_message(message) File "/usr/local/lib/python3.9/site-packages/pypck/connection.py", line 596, in process_message await self.async_process_input(inp) File "/usr/local/lib/python3.9/site-packages/pypck/connection.py", line 614, in async_process_input self.license_error_future.set_result(True) asyncio.exceptions.InvalidStateError: invalid state 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] 51912419f30f5fdb62b68c23e288303b server connected at 192.168.100.129:4114 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: LCN-PCK/IP 1.0 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: Username: 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] to 51912419f30f5fdb62b68c23e288303b: xxx 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: Password: 2021-11-28 14:38:27 DEBUG (MainThread) [pypck.connection] to 51912419f30f5fdb62b68c23e288303b: xxx 2021-11-28 14:38:28 ERROR (MainThread) [homeassistant.components.automation] Platform automation does not generate unique IDs. ID 1608556082243 already exists - ignoring automation.lenny_abwesend 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: OK 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] 51912419f30f5fdb62b68c23e288303b authorization successful! 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] to 51912419f30f5fdb62b68c23e288303b: !CHD 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: $io:#LCN:connected 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] 51912419f30f5fdb62b68c23e288303b: LCN is connected. 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: :M000031Rx002 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] from 51912419f30f5fdb62b68c23e288303b: (dec-mode) 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] 51912419f30f5fdb62b68c23e288303b login successful. 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] to 51912419f30f5fdb62b68c23e288303b: !OM0P 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] to 51912419f30f5fdb62b68c23e288303b: ^ping0 2021-11-28 14:38:28 DEBUG (MainThread) [pypck.connection] 51912419f30f5fdb62b68c23e288303b: No segment coupler found. 2021-11-28 14:38:28 DEBUG (MainThread) [homeassistant.components.lcn] LCN connected to "myhome"

so first PCHK server connected at192.168.100.129:4114 -> failed later

the second try 51912419f30f5fdb62b68c23e288303b server connected at 192.168.100.129:4114 -> ok

are there running mutilple instances of lcn process running?

alengwenus commented 2 years ago

Maybe your configuration is somehow messed up? You could have a look at your [configdir]/.storage/core.config_entries file. If you have removed any LCN integration from the frontend and you still have LCN entries here, that could explain what you reported.

alengwenus commented 2 years ago

Btw.: The first connection is a validation that the PCHK server (your PKE) exists. If yes, your LCN part of the configuration.yaml is imported to the HA's internal configuration (config entry). If not, HA will skip the LCN part and use the internally stored previous configuration. It seems that the latter occurs in your case, because the initial validation fails for whatever reason.

But I can't make sense of why this is happening and why the authentication after sending the password takes so long.

Just for completeness: Could you post your LCN part of the configuration.yaml?

nordmanntanne commented 2 years ago

configuration.yaml lcn: !include lcn.yaml

lcn.yaml connections:

name: myhome host: 192.168.100.129 port: 4114 username: xxx password: xxx

lights:
name: Unten Flur address: myhome.s0.m25 output: output2 dimmable: true transition: 5

nordmanntanne commented 2 years ago

Today deleted lcn integration and there are no lcn entries in [configdir]/.storage/core.config_entries. After restarting the lcn integration did not come up and i see the error and the delay in authentication. Then i upgrade back to 2021.11.5 and everything is fine again. After second restart i see the delay again but the connection is ok anyway.

nordmanntanne commented 2 years ago

I am again having issues. Entity names don't get updated. Still have these timeouts. No idea why. LCN Pro connecting fast. Ping to PKE without drops. Telnet on Port 4114 and login is fast. Restarted everysthing. Have there been any changes in authentication procedure of this integration? The delay between login and answer from pchk is always 12 seconds. Have there been any changes in authentication procedure of this integration? Is there a way for me to edit the timeout in init.py?

establish connection to PCHK server await lcn_connection.async_connect(timeout=15)

In connection.py you it seems you are working with 30 seconds: async def async_connect(self, timeout: int = 30) -> None: """Establish a connection to PCHK at the given socket.

alengwenus commented 2 years ago

I don't have a clue what's going on there. There hasn't been any logical code change in the LCN integration since 06/2021.

I had a look into the code but I cannot reproduce this behavior. I am also using HA version 2021.11.5 (operating system on RPi4 and core only) without any issues.

Have you changed anything in your configuration? Are you using a PKE, PKEV, VISU or the PCHK software? Any firmware update lately? What HA installation type are you using?

Sure you can increase the timeout (in config_flow.py because that's the position where connection validation takes place and the problem occurs). Maybe that helps. However, I would be interested in the root cause.

nordmanntanne commented 2 years ago

I did not change anything in my lcn environment. I can not say how long this problem exist. It is possible that it is longer than 6 month because my lcn config was static once i configured everything. I am using pke v2.06 and LCN-PCHK 3.2.2 on it. No firmware update here. My HA 2021.11.5 is running on RPi4 Home Assistant OS 6.6, supervisor-2021.10.8. Maybe there are other addons or custom integration which affect the lcn integration? Sadly, i have no idea how i can access config_flow.py. I browsed the entire directory but i have no idea where the /homeassistant/components folder is.

home-assistant / core