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
73.8k stars 30.9k forks source link

ElkM1 #118382

Closed RichardUUU closed 5 months ago

RichardUUU commented 5 months ago

The problem

A service call for Elk-M1 to arm_away actually causes elk_armed_state to vacillate: armed_away disarmed armed_away disarmed

What version of Home Assistant Core has the issue?

core-2024.5.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

ElkM1

Link to integration documentation on our website

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

Diagnostics information

home-assistant_elkm1_2024-05-29T12-45-33.901Z.log

Example YAML snippet

sequence:
  - service: alarm_control_panel.alarm_arm_away
    data:
      entity_id: alarm_control_panel.elkm1_main_house
      code: 123456

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 5 months ago

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

Code owner commands Code owners of `elkm1` 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 elkm1` 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)


elkm1 documentation elkm1 source (message by IssueLinks)

gwww commented 5 months ago

It is highly unlikely there is a issue with the code. I looked at your log and your panel is arming and then disarming within milliseconds and the integration has only sent an arm away message. The most likely cause is that your settings for area 1 are causing this.

This is a partial decoding of what I see in the log:

Arm away, area 1
2024-05-29 08:44:51.557 DEBUG (MainThread) [elkm1_lib.connection] write_data '0Da11XXXXXX0035'

Valid user code, user 007
2024-05-29 08:44:51.631 DEBUG (MainThread) [elkm1_lib.connection] got_data '17IC000000000000007010074'

Log data, event 1173 (area armed), user 007, area 1
2024-05-29 08:44:51.837 DEBUG (MainThread) [elkm1_lib.connection] got_data '1CLD1173007108450529000424003D'

2024-05-29 08:44:51.838 DEBUG (MainThread) [elkm1_lib.connection] got_data '1EAS000000001111111100000000000E'
2024-05-29 08:44:51.838 DEBUG (MainThread) [elkm1_lib.connection] got_data '0CAM000000007F'
2024-05-29 08:44:51.838 DEBUG (MainThread) [elkm1_lib.connection] got_data '17IC000000000000007010074'

Arming Status 
2024-05-29 08:44:51.839 DEBUG (MainThread) [elkm1_lib.connection] got_data '1EAS 10000000 41111111 00000000 000A'
2024-05-29 08:44:51.839 DEBUG (MainThread) [elkm1_lib.connection] got_data '0CAM000000007F'

Log data, event 1174 (disarmed)
2024-05-29 08:44:51.839 DEBUG (MainThread) [elkm1_lib.connection] got_data '1CLD1174007108450529000424003C'

You can see that the integration sends exactly one arm message, no other arm/disarm message are in the log. You can also see in the timestamps that the arm-disarm happens in 282 milliseconds -- i.e.: it is the panel arming then disarming.

RichardUUU commented 5 months ago

Here is an interesting wrinkle to consider. That log was created when this automation triggered this script:

# automation
- alias: 'shellyplus2pm-123456 device - Channel 2'
  trigger:
    - platform: event
      event_type: shelly.click
      event_data:
        device: shellyplus2pm-123456
        channel: 2
        click_type: long_push
  action:
    - service: script.turn_on
      target:
        entity_id: script.alarm_arm_away

# script
alarm_arm_away:
  alias: Alarm Arm Away
  mode: single
  sequence:
  - service: alarm_control_panel.alarm_arm_away
    data:
      entity_id: alarm_control_panel.elkm1_main_house
      code: 123456

However, when that same script is called by this automation, the elk does not disarm (until I manually disarm it):

- alias: "Arm Away"
  id: my_id_0090
  trigger:
    - platform: event
      event_type: shelly.click
      event_data:
        device: shellyswitch25-abcdefg 
        channel: 1
        click_type: long
  action:
    - service: script.turn_on
      target:
        entity_id: script.alarm_arm_away

See this log file.

home-assistant_elkm1_2024-05-29T17-44-52.636Z.log

The only difference is that the script is triggered by one type of shelly device or another. If the problem were in the Elk configuration, wouldn't it perform the same for both triggers?

gwww commented 5 months ago

Haven’t looked at the new log yet but in the first log the integration is working as expected.

Could it be that a zone is triggered when trying to arm and the Elk rejects the arming?

I’ll take a look at the new log tonight.

RichardUUU commented 5 months ago

Thanks. The only thing this Shelly switch does is turn on some local lights, and trigger the automation above. I can't imagine how it would affect a zone.

Assuming the integration continues to operate as expected, do you have any suggestions on how to debug?

I'm thinking maybe I delete the Elk integration and add it back via configuration.yaml, but start with no zones and then add them in until it stops working. Or is there a better way?

Thanks, Richard

gwww commented 5 months ago

I doubt deleting and re-adding the integration will make a difference. From the first log the integration is doing exactly what it is supposed to... it's the panel that decided that it would arm then disarm.

RichardUUU commented 5 months ago

Any idea why it might decide to disarm when triggered by one Shelly device and not when triggered by another?

gwww commented 5 months ago

I recommend you take a look at page 30 of the Elk installations and programming manual. In particular the table around zone programming and arming.

As to one Shelly vs. the other it could be that a certain zone is triggered at the time?

gwww commented 5 months ago

Also take a look at this comment and the following one from earlier this year. https://github.com/home-assistant/core/issues/107990#issuecomment-1913687975

RichardUUU commented 5 months ago

No joy from the previous comments. Those two Shelly switches are a few feet from each other. I can try one and it always fails, try the other and it always succeeds. No other changes in the house or zones.

gwww commented 5 months ago

The logs you have provided are not complete. Let's try the logs again. Maybe I will see something new. I'm still of the opinion that the integration is doing the right thing.

Can you turn on logging using the instructions here: https://www.home-assistant.io/integrations/elkm1/#debugging. Follow the configuration.yaml part. Preferably, turn on debugging exactly as shown, so that the logging is focused on the ElkM1 stuff.

After you reboot, run both automations. The broken one followed by the good one. Then provide the new log.

BTW, did you review p.30 of the installation/programming manual? Any hints there for you?

RichardUUU commented 5 months ago

I did review p.30, but it's hard to know what to look for when my current configuration works ... with most of my Shelly switches. I did find success, however, when I added a 1 second delay to the script. That makes me think the problem is somewhere on the HA side -- maybe a problem with the Shelly integration -- but I'm not sure how that would cause Elk to disarm, or why adding a delay would fix it. I'll do some more tests to isolate some variables and report back. This works:

alarm_arm_away:
  alias: Alarm Arm Away
  mode: single
  sequence:
    - delay: '00:00:01'  # Introduces a delay of 1 second
    - service: alarm_control_panel.alarm_arm_away
      data:
        entity_id: alarm_control_panel.elkm1_main_house
        code: !secret elkpass
gwww commented 5 months ago

I don’t have anything more to add. The log shows it’s the panel that responds to the arm message with arm quickly followed by disarm. Based on that the only theory I can think of is the panel’s config.

What else? A full log may reveal something. Maybe with the not working script followed by the one with the one second delay.

I’m out of ideas beyond that.

gwww commented 5 months ago

What version is your panel? I'm posting on the Elk support forum to see if they have any ideas.

RichardUUU commented 5 months ago

Thanks for your diligence. M1G. Hardware: 0.11 Boot: 3.3.6 Firmware: 5.3.14

Because this only happens on a shellyplus device, I have even wondered about the Shelly switch, its firmware, or even the physical buttons (which are momentary). But even if there were some bounce, or signal doubling, or noise it would presumably show up in the logs before Elk acts on it.

Here is a full log with two different scripts triggered by the same shelly device. First, I press Button 1 to trigger the script with the delay which correctly sets the alarm to arm_stay. Then I manually disarm. Then I press Button 2 to trigger the script with no delay.which incorrectly results in disarm.

home-assistant_2024-05-31T13-21-59.788Z.log

gwww commented 5 months ago

The log is incomplete -- there are no arm messages in it. I recommend following what is in this comment to product a log: https://github.com/home-assistant/core/issues/118382#issuecomment-2138377227. All logs to date do not show startup of HA, which can be useful to understand all the things that the Elk is sending.

UPDATE: if you can do the working one first followed by disarm followed by the one that doesn't work. That might make the log a bit easier to see the transition from working to not working.

gwww commented 5 months ago

Do you have any Rules related to Arm / Disarming? If you Arm from the M1 keypad does the system immediately disarm? Are you integrating with any Integration Partners (Crestron, Control 4, AMX, Elan, RTI, UTC, etc.) ? What interface is sending the ASCII string to the M1? What is the Firmware in the M1XEP?

The above is from Brad Weeks, Elk Products engineer. The only question I can answer is the "what interface...".

RichardUUU commented 5 months ago

No Elk rules relate to arming. Keypad arms normally. No integrations except for Home Assistant. M1XEP - Hardware: 1.0 Boot: 2.0.4 Firmware: 2.0.48

Here is the log in accordance with your instructions: home-assistant_elkm1_2024-05-31T19-29-29.344Z.log

In an earlier message, you mentoned: Valid user code, user 007. What if I want to use a different user? How do I specify that in the integration? I added the integration via UI, not configuration.yaml.

gwww commented 5 months ago

User 7 is tied to the access security code. It’s worth trying a different user.

RichardUUU commented 5 months ago

I'm drawing a blank on how to switch users. User 001 is in the Elk system with username: Hassio. I tried adding Hassio as a user in the the M1XEP setup, then deleting the integration and reinstalling with that username, but it didn't work. Do I need to rediscover the integration? Something else?

gwww commented 5 months ago

In you Elk configuration (accessed using ElkRP) there is a user table. Each user has a security code. Looking at the debug log I can see that user 1 is Hassio and user 7 is Master (I can't see the codes, only the user numbers and names). The code you are using is for user 7 (and by the way user's have attributes about what they can do, might be good to review what you've got set). To switch to another user, use that user's security code.

gwww commented 5 months ago

I just poked through the latest log. Good: it is logging from the start. I'm assuming you added the debug config to configuration.yaml. Bad: it does not contain any of the arming attempts. The last log message has a timestamp of 15:29:26.595.

RichardUUU commented 5 months ago

I read somewhere that I should be using a user with Authorization for Master being unchecked. I have done that and it seems like the problem has gone away, although I can't say for sure it wasn't something else I did. I still think it's interesting that a pause in the script also solves the problem. And I have no idea why my logs aren't reporting everything, but perhaps that is now a moot point. Thanks again.

gwww commented 5 months ago

@home-assistant close