Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HA does not capture Insteon i3 Dial Dimmer level #114244

Closed
mark-klink182 opened this issue Mar 26, 2024 · 8 comments · Fixed by #117196
Closed

HA does not capture Insteon i3 Dial Dimmer level #114244

mark-klink182 opened this issue Mar 26, 2024 · 8 comments · Fixed by #117196
Assignees
@teharris1
Labels
integration: insteon

Comments

@mark-klink182
Copy link

The problem

When the i3 Dial Dimmer is turned on by turning the dial, HA does not detect the light is turned on or indicate the light level. It will only change the state to on when the light reaches full brightness. The state would show on and the brightness is 253 (99%). The insteon logs show information is being captured when the dial changes but HA and the insteon integration does not update the device state. Logs are attached and should show when the dimmer is turned up to about 50% after being in an off state.

What version of Home Assistant Core has the issue?

core-2024.3.3

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

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

Diagnostics information

home-assistant_insteon_2024-03-24T14-09-47.329Z.log

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2024-03-24 10:09:24.585 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Buffer from 104 to 170
2024-03-24 10:09:24.588 DEBUG (MainThread) [pyinsteon.protocol.http_transport] New buffer: 0250619576000001CF340D0250619576000001CF340D0250619576000001CF342D
2024-03-24 10:09:24.588 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 020250619576000001cf340d0250619576000001cf340d0250619576000001cf342d
2024-03-24 10:09:24.589 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Error: 2 is not a valid MessageId
2024-03-24 10:09:24.609 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 0250619576000001cf340d0250619576000001cf340d0250619576000001cf342d
2024-03-24 10:09:24.609 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf340d0250619576000001cf340d0250619576000001cf342d
2024-03-24 10:09:24.614 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 0250619576000001cf340d0250619576000001cf342d
2024-03-24 10:09:24.617 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf340d0250619576000001cf342d
2024-03-24 10:09:24.617 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 0250619576000001cf342d
2024-03-24 10:09:24.618 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf342d
2024-03-24 10:09:24.625 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 
2024-03-24 10:09:24.629 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.634 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.635 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.636 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 13, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:24.638 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.639 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.645 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x0d
2024-03-24 10:09:24.647 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 13, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:24.649 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x2d
2024-03-24 10:09:24.649 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x2d
2024-03-24 10:09:24.650 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x2d
2024-03-24 10:09:24.651 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 45, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:25.243 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Raw buffer: 76000001CF346D025C558E6C4B43C3232E02026255AE031F2E02000000000000000000000000929606025C55AE034B43C3232E020250619576000001CF340D0250619576000001CF340D0250619576000001CF342D0250619576000001CF343D025061950E
2024-03-24 10:09:25.243 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Buffer from 170 to 200 and 0 to 14
2024-03-24 10:09:25.243 DEBUG (MainThread) [pyinsteon.protocol.http_transport] New buffer: 0250619576000001CF343D0250619576000001CF346D
2024-03-24 10:09:25.244 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf343d0250619576000001cf346d
2024-03-24 10:09:25.244 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 0250619576000001cf346d
2024-03-24 10:09:25.244 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf346d
2024-03-24 10:09:25.246 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 
2024-03-24 10:09:25.250 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x3d
2024-03-24 10:09:25.251 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x3d
2024-03-24 10:09:25.252 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x3d
2024-03-24 10:09:25.253 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 61, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:25.254 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.256 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.256 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.264 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 109, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:25.869 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Raw buffer: 76000001CF346D0250619576000001CF346D0250619576000001CF346D000000000000000000929606025C55AE034B43C3232E020250619576000001CF340D0250619576000001CF340D0250619576000001CF342D0250619576000001CF343D025061953A
2024-03-24 10:09:25.870 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Buffer from 14 to 58
2024-03-24 10:09:25.870 DEBUG (MainThread) [pyinsteon.protocol.http_transport] New buffer: 0250619576000001CF346D0250619576000001CF346D
2024-03-24 10:09:25.870 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf346d0250619576000001cf346d
2024-03-24 10:09:25.870 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 0250619576000001cf346d
2024-03-24 10:09:25.871 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf346d
2024-03-24 10:09:25.872 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 
2024-03-24 10:09:25.882 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.883 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.884 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.885 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 109, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:25.886 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.887 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.888 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:25.888 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 109, 'target': 000001, 'user_data': None, 'hops_left': 3}
2024-03-24 10:09:26.499 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Raw buffer: 76000001CF346D0250619576000001CF346D0250619576000001CF346D0250619576000001CF346D06025C55AE034B43C3232E020250619576000001CF340D0250619576000001CF340D0250619576000001CF342D0250619576000001CF343D0250619550
2024-03-24 10:09:26.499 DEBUG (MainThread) [pyinsteon.protocol.http_reader_writer] Buffer from 58 to 80
2024-03-24 10:09:26.500 DEBUG (MainThread) [pyinsteon.protocol.http_transport] New buffer: 0250619576000001CF346D
2024-03-24 10:09:26.500 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] IN CREATE: 0250619576000001cf346d
2024-03-24 10:09:26.500 DEBUG (MainThread) [pyinsteon.protocol.messages.inbound] Returning: 
2024-03-24 10:09:26.506 DEBUG (MainThread) [pyinsteon.messages] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:26.508 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:26.508 DEBUG (MainThread) [pyinsteon.000001] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x6d
2024-03-24 10:09:26.509 DEBUG (MainThread) [pyinsteon.topics] Topic: 619576.standard_message_received.all_link_broadcast data: {'cmd1': 52, 'cmd2': 109, 'target': 000001, 'user_data': None, 'hops_left': 3}

Additional information

No response
@home-assistant
Copy link

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 Renames 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.
  • @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)

insteon documentation
insteon source
(message by IssueLinks)

@teharris1
Copy link
Contributor

This looks like it may only be a partial log. Can you do the following:

  1. Turn logging off if it is on
  2. Turn the device off
  3. Turn logging back on
  4. Turn the device on to 50% or so
  5. Wait 10 seconds
  6. Turn the device to full on
  7. Wait 10 seconds
  8. Turn the device to 50% again
  9. Wait 10 seconds
  10. Turn the device to full off
  11. Turn logging off and upload the full log

Thanks

@mark-klink182
Copy link
Author

See attached logs. The i3 Dial ID 619576.
home-assistant_insteon_2024-04-22T22-57-47.042Z.log

@mark-klink182
Copy link
Author

I created a new log of the i3 Dial being pushed on, then after a pause being pushed off. HA will register that the light is on but will not report the light brightness. The previous log is rotating the dial to turn on the light at 50% then 100%, back to 50% then off to 0%.
home-assistant_insteon_2024-04-23T11-30-54.301Z.log

@teharris1
Copy link
Contributor

Thanks for the logs. In the latest log I can see these two messages:

2024-04-23 07:29:42.861 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x11, cmd2: 0x00
2024-04-23 07:30:17.386 DEBUG (MainThread) [pyinsteon.619576] RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x13, cmd2: 0x00

The first one says you turned it on at 7:29:42 and the second one says you turned it off at 7:30:17. There are no messages before that (at least not since 6PM the previous day) and no messages after that to indicate that the device changed state.

Did you pause at the 50% mark for any period of time?

@mark-klink182
Copy link
Author

The log from 2024-04-22T22-57-47.042Z I only turned the dial to turn on and off the light, I waited about 30 seconds in between each action like you originally requested. I never pushed the dial while logging. This is why I added the log from 2024-04-23T11-30-54.301Z that only did the dial push to turn on then off. HA does recognize the on and off when the dial is pressed but it always shows it at 100% brightness and turning the dial to a different brightness does not update HA with the new brightness value.

@teharris1
Copy link
Contributor

Got it. Thanks. I was looking at the wrong log. So now looking at the correct log...

I reached out to the Insteon team. There is an odd message here for cmd1: 0x34. This is not documented but it appears this is the message that the i3 is sending when it changes state manually. I need them to confirm what this message is telling me. Not sure how technical you are but here is what I see in the logs:

Turn to 50%
2024-04-22 18:45:01.318 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcb, cmd1: 0x34, cmd2: 0x0d
2024-04-22 18:45:03.171 RX: msg_id: 0x50, address: 619576, target: 0343c3, flags: 0x20, cmd1: 0x01, cmd2: 0xd0

Turn on
2024-04-22 18:45:30.866 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x8d
2024-04-22 18:45:31.478 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcb, cmd1: 0x34, cmd2: 0x8d
2024-04-22 18:45:31.480 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcb, cmd1: 0x11, cmd2: 0xfd

Turn down to 50%
2024-04-22 18:45:59.359 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcb, cmd1: 0x11, cmd2: 0xfd
2024-04-22 18:45:59.377 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0xfd
2024-04-22 18:45:59.379 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0xed
2024-04-22 18:46:03.653 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x7d
2024-04-22 18:46:03.656 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x4d

Turn off
2024-04-22 18:46:29.031 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x4d
2024-04-22 18:46:29.040 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x34, cmd2: 0x4d
2024-04-22 18:46:29.645 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x13, cmd2: 0x0d
2024-04-22 18:46:29.653 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x13, cmd2: 0x0d
2024-04-22 18:46:30.281 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcf, cmd1: 0x13, cmd2: 0x0d
2024-04-22 18:46:30.291 RX: msg_id: 0x50, address: 619576, target: 000001, flags: 0xcb, cmd1: 0x13, cmd2: 0x0d

I abbreviated the log for readability. Normally I would see an Insteon message 0x17 that would notify the network that the device is being changed manually followed by a 0x18 to notify the network that the device is done being changed. Once I see the 0x18, I ask for the device status to get the on level of the device. In this case I don't see that message command but the device appears to consistently send the 0x34 message instead.

Once I get confirmation from Insteon I can update the library to get this fixed.

@teharris1
Copy link
Contributor

I got the info I needed from Insteon and was able to confirm it using an i3 dial that they sent me. It will be in an HA release in the next week or so.

@teharris1 teharris1 mentioned this issue May 10, 2024
Merged
20 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@teharris1 teharris1

Labels
integration: insteon
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Bump pyinsteon to 1.6.1 teharris1/home-assistant
2 participants
@teharris1 @mark-klink182