search

home-assistant / core

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

Insteon not responding to IOLinc correctly, or at all #83207

Closed dscottbuch closed 1 year ago

dscottbuch commented 1 year ago

The problem

I've added several IOLinc devices to a fresh install of HA with the INSTEON Integration and the sensor is only very occasionally responsive. All of these work fine with Indigo (I'm evaluation switching). The sensor inputs are closed then opened and no event is logged.

What version of Home Assistant Core has the issue?

11.5

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

INSTEON

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

There are no log entries about this I can find.

Additional information

No response

dscottbuch commented 1 year ago

Currently, after some more testing. The sensor, which is open, is detected as open after every server restart for about 30 seconds. Then a 'detected' event (it's configured as a motion sensor) occurs, even though nothing changed, and never clears again.

home-assistant[bot] commented 1 year ago

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

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

(message by CodeOwnersMention)

insteon documentation insteon source (message by IssueLinks)

dscottbuch commented 1 year ago

Any thoughts on this?

teharris1 commented 1 year ago

Can you tell me what is in your All Link Database for your Modem and your IO Link? Generally these issues are fixed by adding the default links to the modem and the device. Were the devices linked to the modem using Home Assistant or some other way?

dscottbuch commented 1 year ago

They were the default links added by Home Assistant. I factory reset everything and started from scratch so that would be the case. The links are below.

I have had 1 time, after upgrading the core that the log showed the event of a test button push that I have connected to the sensor terminals. Nothing after that. I have a separated PLM that I use with Indigo and the same test setup and that works OK.

I’ve been poking through the code starting to learn how this HA system works. I note in the Insteon component that I don’t see and async_fire(event) calls except for a group change. Also, all update_ha_state are scheduled_update_ha_state calls so I was thinking the on and off are both scheduled and cancel before the main loop can respond?

Just a thought as I’m just getting into this.

Thanks,

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Jan 18, 2023, at 12:57 PM, Tom Harris @.***> wrote:

Can you tell me what is in your All Link Database for your Modem and your IO Link? Generally these issues are fixed by adding the default links to the modem and the device. Were the devices linked to the modem using Home Assistant or some other way?

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1396077156, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMPQALDSJYYTLANW2VTWTBKLDANCNFSM6AAAAAASS546KY. You are receiving this because you authored the thread.



teharris1 commented 1 year ago

OK, then let's debug the IO Link traffic and responses. In your config directory is a file called configuration.yaml. Please add the following lines to that file:

logger:
  default: warning
  logs:
    pyinsteon.1a2b3c: debug

Where 1a2b3c is the actual Insteon address of your device. Once this is in place, restart Home Assistant and test the device. The results will be in the log file which you can find by going to Settings -> System -> Logs. Download the log and upload it to this ticket.

teharris1 commented 1 year ago

Also, don't use email to attache the log. Do it from a web browser. Email does not work well with git issues.

dscottbuch commented 1 year ago

OK. Thanks. I’m aware as I’ve done some open source work in the past on GitHub - cTivo

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Jan 19, 2023, at 7:23 AM, Tom Harris @.***> wrote:

Also, don't use email to attache the log. Do it from a web browser. Email does not work well with git issues.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1397146500, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMIWLML4OIDHLRN7ZLLWTFL7LANCNFSM6AAAAAASS546KY. You are receiving this because you authored the thread.

dscottbuch commented 1 year ago

Here's the result. I also put a screenshot of the Device display of the log. home-assistant_2023-01-19T16-03-43.836Z.log Screenshot 2023-01-19 at 8 04 46 AM

dscottbuch commented 1 year ago

Forgot to mention that shortly after 8:00 AM I pressed the test button once.

teharris1 commented 1 year ago

I see what the issue is but it is not an easy fix. I have a change coming in the next few weeks that may address it but I will continue to evaluate how to make this device respond better. The problem with the IO Link device is that the sensor and the relay are both on the same group number. So when you get a notification that a change has happened you have to query the device to see which one changed. In this case we are seeing the event come in and the query go out but the device is not responding to the query. Could be a device problem except you are saying it is working with the other solution. I have 2 IOLinks at home and they work fine so it is not an issue 100% of the time.

dscottbuch commented 1 year ago

Thanks. I've been looking at further examples that might help. Here are 4 more occurrences and I've tried to highlight the key entries. There looks to always be a starting message that shows the "Light On" command, 0x11, that's sent to group 1. Then on three out of the four there is a 'Light Off' command, 0x13, sent to the PLM. On 1 of the 4 there is also a 'Light Off' command, 0x13, sent to group 1 first then the 'Light Off' command, 0x13, sent to the PM. What I'm looking for is an HA event on the first 'Light On' message. Am I just missing how to access that for an automation, etc.? HASS_IOLINC_Log_Examples.pdf

dscottbuch commented 1 year ago

I’ve continued to try to understand this, also by looking at the automation sw I’m currently using. My understanding of the IOLink is that the sensors is strictly an input device and the really an output device, i.e. there is no button on the device that will activate the relay in normal use. The relay is activated by either an external message or the sensor device so that any initial message coming from the IOlinc would be safe to assume it’s coming from the sensor.

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Jan 21, 2023, at 11:41 AM, Tom Harris @.***> wrote:

I see what the issue is but it is not an easy fix. I have a change coming in the next few weeks that may address it but I will continue to evaluate how to make this device respond better. The problem with the IO Link device is that the sensor and the relay are both on the same group number. So when you get a notification that a change has happened you have to query the device to see which one changed. In this case we are seeing the event come in and the query go out but the device is not responding to the query. Could be a device problem except you are saying it is working with the other solution. I have 2 IOLinks at home and they work fine so it is not an issue 100% of the time.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1399319397, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMMAVLAYUCDBZAQ6YG3WTQ3WRANCNFSM6AAAAAASS546KY. You are receiving this because you authored the thread.

teharris1 commented 1 year ago

HA Release 2023.2.4 was released the other day. It has a new version of the pyinsteon library which may help. That library has some underlying improvements that are focused on stability and "may" address this issue.

teharris1 commented 1 year ago

Nevermind, turns out it is not in 2023.2.4 or even 2023.2.5. I need to get with the moderators to get this into the next release. I am sure it will be in 2023.3 but hoping sooner.

dscottbuch commented 1 year ago

Ok. Thanks. I’m currently traveling and couldn’t test for another week in any case. Scott Buchanan30475 SW Buckhaven Rd. Hillsboro, OR  97123On Feb 15, 2023, at 2:06 PM, Tom Harris @.***> wrote: Nevermind, turns out it is not in 2023.2.4 or even 2023.2.5. I need to get with the moderators to get this into the next release. I am sure it will be in 2023.3 but hoping sooner.

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>

teharris1 commented 1 year ago

It is in 2023.3 and is available in the beta version right now. I expect the full release of 2023.3.0 to be release today. Please upgrade to that (or the beta version if you want) and see whether that fixes it.

teharris1 commented 1 year ago

@dscottbuch any improvement with 2023.3?

dscottbuch commented 1 year ago

Doesn’t seem to behave any differently.

Here’s the log output

2023-03-06 10:33:08.733 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x13, cmd2: 0x00 2023-03-06 10:33:08.734 DEBUG (MainThread) [pyinsteon.43aacd] Topic: 43aacd.1.off.all_link_broadcast data: {'cmd1': 19, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2} 2023-03-06 10:33:08.735 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.1.off.all_link_broadcast data: {'on_level': 0} 2023-03-06 10:33:08.736 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:08.736 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:08.763 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:08.764 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:14.769 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:14.769 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:14.799 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x11, cmd2: 0x00 2023-03-06 10:33:14.799 DEBUG (MainThread) [pyinsteon.43aacd] Topic: 43aacd.1.on.all_link_broadcast data: {'cmd1': 17, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2} 2023-03-06 10:33:14.799 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.1.on.all_link_broadcast data: {'on_level': 255} 2023-03-06 10:33:14.800 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:14.800 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:14.801 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:15.572 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:15.597 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:15.598 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:15.599 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 2023-03-06 10:33:16.374 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 2023-03-06 10:33:16.399 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x15 2023-03-06 10:33:16.399 DEBUG (MainThread) [pyinsteon.43aacd] Topic: nak.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 2023-03-06 10:33:16.602 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 2023-03-06 10:33:16.602 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:17.178 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 2023-03-06 10:33:17.198 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06 2023-03-06 10:33:17.198 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 2023-03-06 10:33:17.981 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:17.994 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x15 2023-03-06 10:33:17.994 DEBUG (MainThread) [pyinsteon.43aacd] Topic: nak.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:18.397 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:18.783 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:18.808 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:18.808 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:20.803 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:20.804 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:20.821 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:20.822 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:21.601 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:21.606 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:21.619 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x15 2023-03-06 10:33:21.620 DEBUG (MainThread) [pyinsteon.43aacd] Topic: nak.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:21.823 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 2023-03-06 10:33:22.409 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 2023-03-06 10:33:22.431 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 2023-03-06 10:33:22.431 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None} 2023-03-06 10:33:23.202 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 2023-03-06 10:33:23.215 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 2023-03-06 10:33:23.245 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06 2023-03-06 10:33:23.245 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 2023-03-06 10:33:24.457 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x50, address: 43aacd, target: 50023f, flags: 0x46, cmd1: 0x11, cmd2: 0x01 2023-03-06 10:33:24.458 DEBUG (MainThread) [pyinsteon.43aacd] Topic: 43aacd.1.on.all_link_cleanup data: {'cmd1': 17, 'cmd2': 1, 'target': 50023f, 'user_data': None, 'hops_left': 1} 2023-03-06 10:33:24.458 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.1.on.all_link_cleanup data: {} 2023-03-06 10:33:24.813 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 2023-03-06 10:33:24.814 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 2023-03-06 10:33:24.842 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06 2023-03-06 10:33:24.843 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 2023-03-06 10:33:28.173 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x50, address: 43aacd, target: 50023f, flags: 0x2b, cmd1: 0x00, cmd2: 0x00 2023-03-06 10:33:28.174 DEBUG (MainThread) [pyinsteon.43aacd] Topic: 43aacd.standard_message_received.direct_ack data: {'cmd1': 0, 'cmd2': 0, 'target': 50023f, 'user_data': None, 'hops_left': 2} 2023-03-06 10:33:28.235 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.0.status_request.direct data: {'db_version': 0, 'status': 0} 2023-03-06 10:33:28.236 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.1.status_request.direct data: {'db_version': 0, 'status': 0} 2023-03-06 10:33:30.845 DEBUG (MainThread) [pyinsteon.43aacd] Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 2023-03-06 10:33:30.847 DEBUG (MainThread) [pyinsteon.43aacd] TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 2023-03-06 10:33:30.871 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06 2023-03-06 10:33:30.872 DEBUG (MainThread) [pyinsteon.43aacd] Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 2023-03-06 10:33:31.730 DEBUG (MainThread) [pyinsteon.43aacd] RX: msg_id: 0x50, address: 43aacd, target: 50023f, flags: 0x26, cmd1: 0x00, cmd2: 0x00 2023-03-06 10:33:31.731 DEBUG (MainThread) [pyinsteon.43aacd] Topic: 43aacd.standard_message_received.direct_ack data: {'cmd1': 0, 'cmd2': 0, 'target': 50023f, 'user_data': None, 'hops_left': 1} 2023-03-06 10:33:31.793 DEBUG (MainThread) [pyinsteon.43aacd] Topic: handler.43aacd.0.status_request.direct data: {'db_version': 0, 'status': 0}

The Device Interface on the Log Card shows.

I/O Linc 43.AA.CD Sensor detected 10:24:17 AM - 12 minutes ago I/O Linc 43.AA.CD Sensor detected 10:20:16 AM - 16 minutes ago

Which corresponds to reboots/restarts of the system with various upgrades I did this morning.

System => 2023.3.1

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 6, 2023, at 10:08 AM, Tom Harris @.***> wrote:

@dscottbuch https://github.com/dscottbuch any improvement with 2023.3?

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1456679054, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMMZ2XNA4NWYCYDUIX3W2YR3PANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.

teharris1 commented 1 year ago

I’ve continued to try to understand this, also by looking at the automation sw I’m currently using. My understanding of the IOLink is that the sensors is strictly an input device and the really an output device, i.e. there is no button on the device that will activate the relay in normal use. The relay is activated by either an external message or the sensor device so that any initial message coming from the IOlinc would be safe to assume it’s coming from the sensor.

Not exactly correct. The IOLinc has a button on the side that glows when the relay is on and is off when the relay is off. So the issue with the IOLinc is that messages from the device can be either the relay or the sensor both coming as group 1. It is a very poor design from my perspective and requires that all messages from the device trigger a status request to both the sensor and the relay individually. What is happening in your case is the on (0x11) and the off (0x13) are coming close to one another. I am not sure why this is happening, but the result of this is the two status messages are overlapping one another making it a bit more difficult to understand. The issue I am concerned about is that the device does not seem to respond to the status request in a timely manner. I am really not sure why this is happening. If you look at the most recent logs you see:

# Something was turned OFF at the device
3/6/2023    10:33:08.733    RX:  msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x13, cmd2: 0x00
3/6/2023    10:33:08.734    Topic:   43aacd.1.off.all_link_broadcast data: {'cmd1': 19, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2}
3/6/2023    10:33:08.735    Topic:   handler.43aacd.1.off.all_link_broadcast data: {'on_level': 0}

# Sensor status request sent to the device and acknowledged by the modem that it was sent but never acknowledged by the device as received
3/6/2023    10:33:08.736    Topic:   send.status_request.direct data: {'address': 43aacd, 'status_type': 1}
3/6/2023    10:33:08.736    TX:  msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01
3/6/2023    10:33:08.763    RX:  msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06
3/6/2023    10:33:08.764    Topic:   ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None}

# Sensor status request sent again but never acknowledged by the modem that it was sent
3/6/2023    10:33:14.769    Topic:   send.status_request.direct data: {'address': 43aacd, 'status_type': 1}
3/6/2023    10:33:14.769    TX:  msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01

# Something was turned ON at the device
3/6/2023    10:33:14.799    RX:  msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x11, cmd2: 0x00
3/6/2023    10:33:14.799    Topic:   43aacd.1.on.all_link_broadcast data: {'cmd1': 17, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2}
3/6/2023    10:33:14.799    Topic:   handler.43aacd.1.on.all_link_broadcast data: {'on_level': 255}

The OFF message starts a cycle of asking for status then the ON message starts a new process to ask for status. This results in messages overlapping each other. I am not overly worried about that but if you see that at 10:33:08.764 the modem sent the message to the device for a status of the sensor but by 10:33:14.768 (i.e. 6 seconds later) the device still had not responded to that request. That is the behavior I am trying to figure out. Why does the device respond to the status request on startup but then fail to respond on subsequent requests. At the same time you see in the logs:

# Relay status request sent to the device and the device successfully responds
3/6/2023    10:33:30.845    Topic:   send.status_request.direct data: {'address': 43aacd, 'status_type': 0}
3/6/2023    10:33:30.847    TX:  msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00
3/6/2023    10:33:30.871    RX:  msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06
3/6/2023    10:33:30.872    Topic:   ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None}
3/6/2023    10:33:31.730    RX:  msg_id: 0x50, address: 43aacd, target: 50023f, flags: 0x26, cmd1: 0x00, cmd2: 0x00
3/6/2023    10:33:31.731    Topic:   43aacd.standard_message_received.direct_ack data: {'cmd1': 0, 'cmd2': 0, 'target': 50023f, 'user_data': None, 'hops_left': 1}
3/6/2023    10:33:31.793    Topic:   handler.43aacd.0.status_request.direct data: {'db_version': 0, 'status': 0}

So, the device can still respond to the status requests but sometimes it does and at other times it does not. Can you send me the current property settings of the device and the ALDB of it as well? Include in the properties any of the advanced properties, which you can see by clicking on the three dots menu in the upper right corner.

dscottbuch commented 1 year ago

The reason the messages are close in time is that the input to the sensor is connected to the output of an inductive detection system located next to our driveway entrance. This lets us know when a vehicle enters are leaves our driveway (we have a long drive :) ). This is why the sensor on/off is only 1 second or so.

Here is the property list.

program_lock_on Program lock on No false

blink_on_tx_on Blink on tx on No true

x10_off X10 off No false

sense_sends_off Sense sends off No true

momentary_delay Delay in seconds for the relay to turn on/off (depends on relay mode) No 2

relay_mode Set the relay mode (see owners manual for a description of the options) No Momentary A

ALDB

4063 Yes No 50.02.3F PowerLinc USB Modem 50.02.3F 2 Responder
4055 Yes No 50.02.3F PowerLinc USB Modem 50.02.3F 1 Controller
4047 Yes No 50.02.3F PowerLinc USB Modem 50.02.3F 3 Controller

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 6, 2023, at 2:13 PM, Tom Harris @.***> wrote:

I’ve continued to try to understand this, also by looking at the automation sw I’m currently using. My understanding of the IOLink is that the sensors is strictly an input device and the really an output device, i.e. there is no button on the device that will activate the relay in normal use. The relay is activated by either an external message or the sensor device so that any initial message coming from the IOlinc would be safe to assume it’s coming from the sensor.

Not exactly correct. The IOLinc has a button on the side that glows when the relay is on and is off when the relay is off. So the issue with the IOLinc is that messages from the device can be either the relay or the sensor both coming as group 1. It is a very poor design from my perspective and requires that all messages from the device trigger a status request to both the sensor and the relay individually. What is happening in your case is the on (0x11) and the off (0x13) are coming close to one another. I am not sure why this is happening, but the result of this is the two status messages are overlapping one another making it a bit more difficult to understand. The issue I am concerned about is that the device does not seem to respond to the status request in a timely manner. I am really not sure why this is happening. If you look at the most recent logs you see:

Something was turned OFF at the device

3/6/2023 10:33:08.733 RX: msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x13, cmd2: 0x00 3/6/2023 10:33:08.734 Topic: 43aacd.1.off.all_link_broadcast data: {'cmd1': 19, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2} 3/6/2023 10:33:08.735 Topic: handler.43aacd.1.off.all_link_broadcast data: {'on_level': 0}

Sensor status request sent to the device and acknowledged by the modem that it was sent but never acknowledged by the device as received

3/6/2023 10:33:08.736 Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 3/6/2023 10:33:08.736 TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01 3/6/2023 10:33:08.763 RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01, ack: 0x06 3/6/2023 10:33:08.764 Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 1, 'user_data': None}

Sensor status request sent again but never acknowledged by the modem that it was sent

3/6/2023 10:33:14.769 Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 1} 3/6/2023 10:33:14.769 TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x01

Something was turned ON at the device

3/6/2023 10:33:14.799 RX: msg_id: 0x50, address: 43aacd, target: 000001, flags: 0xcb, cmd1: 0x11, cmd2: 0x00 3/6/2023 10:33:14.799 Topic: 43aacd.1.on.all_link_broadcast data: {'cmd1': 17, 'cmd2': 0, 'target': 000001, 'user_data': None, 'hops_left': 2} 3/6/2023 10:33:14.799 Topic: handler.43aacd.1.on.all_link_broadcast data: {'on_level': 255} The OFF message starts a cycle of asking for status then the ON message starts a new process to ask for status. This results in messages overlapping each other. I am not overly worried about that but if you see that at 10:33:08.764 the modem sent the message to the device for a status of the sensor but by 10:33:14.768 (i.e. 6 seconds later) the device still had not responded to that request. That is the behavior I am trying to figure out. Why does the device respond to the status request on startup but then fail to respond on subsequent requests. At the same time you see in the logs:

Relay status request sent to the device and the device successfully responds

3/6/2023 10:33:30.845 Topic: send.status_request.direct data: {'address': 43aacd, 'status_type': 0} 3/6/2023 10:33:30.847 TX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00 3/6/2023 10:33:30.871 RX: msg_id: 0x62, address: 43aacd, flags: 0x00, cmd1: 0x19, cmd2: 0x00, ack: 0x06 3/6/2023 10:33:30.872 Topic: ack.43aacd.status_request.direct data: {'cmd1': 25, 'cmd2': 0, 'user_data': None} 3/6/2023 10:33:31.730 RX: msg_id: 0x50, address: 43aacd, target: 50023f, flags: 0x26, cmd1: 0x00, cmd2: 0x00 3/6/2023 10:33:31.731 Topic: 43aacd.standard_message_received.direct_ack data: {'cmd1': 0, 'cmd2': 0, 'target': 50023f, 'user_data': None, 'hops_left': 1} 3/6/2023 10:33:31.793 Topic: handler.43aacd.0.status_request.direct data: {'db_version': 0, 'status': 0} So, the device can still respond to the status requests but sometimes it does and at other times it does not. Can you send me the current property settings of the device and the ALDB of it as well? Include in the properties any of the advanced properties, which you can see by clicking on the three dots menu in the upper right corner.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1457090088, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMMJVMAAGGIP6XLRXFDW2ZOQZANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.

teharris1 commented 1 year ago

OK, now I get it. So fundamentally what is happening here is the sensor is ON in the normal state. When a car passes by it moves to OFF then to ON again but pretty quickly. The device looks like it is not responding to the status requests that are coming from the OFF message fast enough then when they do respond to the status requests from the ON message the sensor is back to the ON state therefore you do not see any event occurring. The issue I am still struggling with is why the device is not responding to the status requests in a timely manner on an intermittent basis. So, can you put the system in full debug mode? You can do this by going to Settings -> Devices & Services -> Insteon -> three dot menu -> Enable debug logging. Trigger the device then go back to Settings -> Devices & Services -> Insteon -> three dot menu -> Disable debug logging. This will automatically download a log file. Upload this file and let's see if anything is happening with those status requests at all.

dscottbuch commented 1 year ago

Here’s the downloaded file.

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 6, 2023, at 3:23 PM, Tom Harris @.***> wrote:

OK, now I get it. So fundamentally what is happening here is the sensor is ON in the normal state. When a car passes by it moves to OFF then to ON again but pretty quickly. The device looks like it is not responding to the status requests that are coming from the OFF message fast enough then when they do respond to the status requests from the ON message the sensor is back to the ON state therefore you do not see any event occurring. The issue I am still struggling with is why the device is not responding to the status requests in a timely manner on an intermittent basis. So, can you put the system in full debug mode? You can do this by going to Settings -> Devices & Services -> Insteon -> three dot menu -> Enable debug logging. Trigger the device then go back to Settings -> Devices & Services -> Insteon -> three dot menu -> Disable debug logging. This will automatically download a log file. Upload this file and let's see if anything is happening with those status requests at all.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1457202779, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMPE4LI2S6GPXK4YH6TW2ZWWLANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.



teharris1 commented 1 year ago

You cannot add a file from an email reply. You need to log into the website to upload.

dscottbuch commented 1 year ago

here's the file.

home-assistant_insteon_2023-03-06T23-52-52.306Z.log

teharris1 commented 1 year ago

The most recent logs tell the full story. The device is sending clean up messages after each broadcast message. This is why the status command is not responded, basically the device is too busy to respond. The other software you are using is assuming any message from the device is the sensor. Unfortunately, that is not correct. The relay sends the same message when it is triggered at the device. Here is what I can do. I can add an event that fires for any ON or OFF message that comes from the device. It will not tell you if it is the sensor or the relay so if someone comes by and presses the relay button on the device it would appear same as if the sensor was triggered. If this will work for you then I will get it in to HA in the next few days depending on how long it takes for the approval process.

dscottbuch commented 1 year ago

That would work great. Thanks. Scott Buchanan30475 SW Buckhaven Rd. Hillsboro, OR  97123On Mar 6, 2023, at 7:16 PM, Tom Harris @.***> wrote: The most recent logs tell the full story. The device is sending clean up messages after each broadcast message. This is why the status command is not responded, basically the device is too busy to respond. The other software you are using is assuming any message from the device is the sensor. Unfortunately, that is not correct. The relay sends the same message when it is triggered at the device. Here is what I can do. I can add an event that fires for any ON or OFF message that comes from the device. It will not tell you if it is the sensor or the relay so if someone comes by and presses the relay button on the device it would appear same as if the sensor was triggered. If this will work for you then I will get it in to HA in the next few days depending on how long it takes for the approval process.

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: @.***>

dscottbuch commented 1 year ago

Tom,

I was confused by your comment that there was a button on the side of the IOLinc that would trigger the relay. I don't think that's the case, at least I can't find any on my unit. The only button on the side of mine is the Set button. There is the status light that gives an indication of the relay activation (along with other indications) but you can't activate the relay manually, locally as far as I know. There either has to be an Insteon message sent to the relay or the sensor input changed. I was frustrated by this in years past when putting together an installation as I had to create an Insteon button in the software to provide testing of the relay (or hook up a local button to the sensor inputs).

I think this means your solution will work great.

Thanks again.

teharris1 commented 1 year ago

If you press the set button once and do not hold it down it triggers the relay. You can see this in the attached user manual at the bottom of page 5. I it is not obvious however:

Any device that is Linked to I/O Linc (the load) using these instructions will be controlled when: 
• The I/O Linc connected to the sensor is either opened or closed
• The I/O Linc Set button is tapped

2450-en.pdf

dscottbuch commented 1 year ago

Thanks. I’ve totally missed that for years :)

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 7, 2023, at 10:12 AM, Tom Harris @.***> wrote:

If you press the set button once and do not hold it down it triggers the relay. You can see this in the attached user manual at the bottom of page 5. I it is not obvious however:

Any device that is Linked to I/O Linc (the load) using these instructions will be controlled when: • The I/O Linc connected to the sensor is either opened or closed • The I/O Linc Set button is tapped 2450-en.pdf https://github.com/home-assistant/core/files/10912504/2450-en.pdf — Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1458616245, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMMGRZ52CZN2Z5QSYW3W253B5ANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.

teharris1 commented 1 year ago

I submitted a pull request that addresses your issue. When that PR is merged it will close this ticket automatically. To use the new event, you can create an automation that is triggered base on event. The event name will be insteon.button_on or insteon.button_off depending on which event you want to trigger off of. In the data field you should enter the following:

address: "43aacd"
group: 0

This will filter on that specific device and the device level (aka group 0) events.

dscottbuch commented 1 year ago

Great. Again thanks.

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 7, 2023, at 11:31 AM, Tom Harris @.***> wrote:

I submitted a pull request that addresses your issue. When that PR is merged it will close this ticket automatically. To use the new event, you can create an automation that is triggered base on event. The event name will be insteon.button_on or insteon.button_off depending on which event you want to trigger off of. In the data field you should enter the following:

address: "43aacd" group: 0 This will filter on that specific device and the device level (aka group 0) events.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1458709815, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMLDJ7FLVGIGP5T752TW26EKTANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.

dscottbuch commented 1 year ago

Tom,

Just FYI. I’ve tested these several times over several updates and have now seen no difference in behaviour. I’m running home assistant 2023.3.5

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 8, 2023, at 8:39 AM, Tom Harris @.***> wrote:

Closed #83207 https://github.com/home-assistant/core/issues/83207 as completed.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#event-8698367067, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMNYNZLGQ662YYK2F33W3CY5NANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.

teharris1 commented 1 year ago

When you say you see no difference, you should be seeing an event come in ever time the sensor is triggered that is called insteon.button_on or insteon.button_off with group 0. This is to be used in an automation. The sensor will not update because it is unclear still if the event is a sensor change or a button change. Think about the sensor in Home Assistant as a stateful entity whereas the event is the trigger of a state change. I opened up the event for your specific use case.

dscottbuch commented 1 year ago

Thanks. That’s working now. I didn’t understand your original message.

Again, thanks,

Scott Buchanan

30475 SW Buckhaven Rd. Hillsboro, OR 97123

On Mar 22, 2023, at 4:58 PM, Tom Harris @.***> wrote:

When you say you see no difference, you should be seeing an event come in ever time the sensor is triggered that is called insteon.button_on or insteon.button_off with group 0. This is to be used in an automation. The sensor will not update because it is unclear still if the event is a sensor change or a button change. Think about the sensor in Home Assistant as a stateful entity whereas the event is the trigger of a state change. I opened up the event for your specific use case.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/83207#issuecomment-1480401853, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAPSRMOWXOHJ3ARUJJWPOMLW5OGZDANCNFSM6AAAAAASS546KY. You are receiving this because you were mentioned.