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.

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

Changes to device states not reflected in Home Assistant #288

Open
patrickabernathy opened this issue May 31, 2023 · 131 comments
Open

Changes to device states not reflected in Home Assistant #288

patrickabernathy opened this issue May 31, 2023 · 131 comments
Labels
bug Something isn't working

Comments

@patrickabernathy
Copy link

I've been testing version 3.0.1 and the new version 3.0.2 but both versions seem to do an initial poll but after a few minutes just stops. In the debug logs I see the initial poll request then nothing else. I've been arming and disarming my system in an attempt to get it to trigger but no response from my integrations. I've switched back to v2.2.2 and everything seems to work normally with the 30 second poll timer.

@lbreggi
Copy link

lbreggi commented Jun 1, 2023

Same here - is there something I can do to help to identify the issue? Thanks!

@ghds514
Copy link

ghds514 commented Jun 1, 2023

Greatly appreciate everything being done for this plugin.

Also experiencing this. When moving from 2.2.2 to 3.0.1, polling it seemed like everything was working correctly once I added 2FA authentication to my account. When I moved to 3.0.2, HA reported a need to reconfigure the plugin, although it appeared to continue to function correctly. Once I re-authenticated for 3.0.2, the Arming status stopped updating.

Let me know if there is anything I can do to help.

@elahd
Copy link
Collaborator

elahd commented Jun 1, 2023

v3.0.3 fixes the alarm status issue. Can you try that?

@lbreggi
Copy link

lbreggi commented Jun 2, 2023

I believe the arm / disarm is now working again with the 3.0.3 but the feedback about locks still not working

@TheWebMachine
Copy link

Arm/Disarm status still not updating properly for me in 3.0.3. If I manipulate from HA, it updates status. If it is armed/disarmed elsewhere, the status never updates and my automations in HA never run. Reverting back to 2.2.2 for now.

@ghds514
Copy link

ghds514 commented Jun 4, 2023

I believe everything is working correctly for me in 3.0.3. It does seem that a change in arming status takes loner to be reflected in HA than before, but I do see that there is a setting in the configuration that may allow for modification of this.

@TheWebMachine
Copy link

Ugh...forgot 2.2.2 was funky, too. I'm rolling back to 2.2.1 until v3.x is resolved. Between 3.0.3, 3.0.2, and 2.2.2, I've had 3 false alarms incidents on my system because of these status polling issues...I basically can't rely on HA at all for this at the moment or else I risk losing my alarm permit from all the false alarms. 🤦🏻‍♂️

3.0.3 polls correctly for no more than 20 minutes after the integration is loaded/reloaded and if you manipulate via HA, polling works again for a while. The moment anything outside of HA happens to the system (scheduled arming, manual arming, etc), the polling completely stops until I perform an action against alarm.com via HA or reload the integration. 🤷🏻‍♂️

@elahd
Copy link
Collaborator

elahd commented Jun 8, 2023

Test out v3.0.4-beta.1. WebSockets work more reliably now (on my account, at least). If you're still running into trouble, go into the integration's settings page and set a low poll time.

@elahd
Copy link
Collaborator

elahd commented Jun 8, 2023

Use v3.0.4-beta.2. There's a bug in beta.1 that ignores user-entered polling intervals.

@TheWebMachine
Copy link

Use v3.0.4-beta.2. There's a bug in beta.1 that ignores user-entered polling intervals.

So far, so good. A little over an hour into updating. I have my polling set to 30 seconds (have since the option became available in v2.x) and when I externally manipulate the panel, it takes no more than 30 seconds to show up in HA, which is actually about as long as it takes ADC to send me the SMS alert, so that is what I expect.

I'll keep testing throughout the day and with different intervals and report back. I'll be able to leave the house idle for a few hours while I go run some errands, which will give time for polling to start failing again if it's going to, as that's usually when I notice it stop working...and how I've accidentally set my system off a few times before forgetting we were pecking at a bug. hahaha

@lbreggi
Copy link

lbreggi commented Jun 8, 2023

I'm also trying the beta and so far seems to be working fine! I'm still with the feeling that the 2.x version was reflecting changes faster in the dashboard, but the way it is in the beta is totally fine. I will keep testing. Thanks!

@elahd elahd changed the title Polling stops in 3.0.2 Changes to device states not reflected in Home Assistant Jun 9, 2023
@elahd
Copy link
Collaborator

elahd commented Jun 9, 2023

@jprasm / @sspaul1976: Can you post details about the delays you posted about in #289? There are delays that are inherent to Alarm.com's infrastructure, so I want to confirm whether the delays that you're experiencing are expected or unexpected.

Expected behavior is below. See the release notes for v3.0.3 for details regarding why this is the case.

  1. Actions initiated through Home Assistant may take up to 60 seconds to complete. This includes commands for your alarm, locks, garage doors, etc.
  2. Changes to Door/Window/Motion sensors and actions taken outside of Home Assistant may take up to 3 minutes to register via push notification and may not register at all. If you have a low poll time, you should expect to see the same refresh times that you saw in the v2.x version of this integration.

Also, can you confirm the refresh interval that is set for the integration?

@jprasm
Copy link

jprasm commented Jun 9, 2023

Hi elahd,

I only use this integration to arm and disarm my alarm system - I know that there is a delay with the various window and door sensors, and I know that's normal behaviour (the delay on door/window sensors is so long that I don't use them for any automations unfortunately).

With 2.2.1 the arm/disarm of my system is nearly instantaneous! Love it.
However, when I upgrade to the latest, there is a significant delay in arm/disarm (15-30 seconds at least). Not good!

I have the update interval set at 15 seconds.

@TheWebMachine
Copy link

Are you on the latest 3.0.4-beta2? Arm/Disarm from within HA is under 5s for me in the latest beta, regardless of polling interval.

@catellie
Copy link

catellie commented Jun 9, 2023

@elahd [continuing from other thead] I thought I was using the actual release (3.0.4), but as I checked my logs it looks like the restart somehow didn't work out so I expect it might be in a state of flux (downloaded, but not yet successfully restarted).

A closer examination of the logs indicates that I may have jumped the gun a bit: It did indeed get into the correct state just minutes later - roughly 10 minutes after I armed away. I can see this event just before the door event:

023-06-09 07:18:51.315 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client]
====================[ WEBSOCKET MESSAGE: BEGIN ]====================
{
    "EventDateUtc": "2023-06-09T05:18:51.068Z",
    "UnitId": REDACTED,
    "DeviceId": 127,
    "EventType": 10,
    "EventValue": 0.0,
    "CorrelatedId": null,
    "QstringForExtraData": "ew=&ew_contact_user_type=-1",
    "DeviceType": -1
}
2023-06-09 07:18:51.315 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] WebSocket Message Type: Event
2023-06-09 07:18:51.315 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got async update for partition1 (REDACTED) from WebSocket message with new {'state': 3, 'desiredState': 3}.
2023-06-09 07:18:51.316 DEBUG (MainThread) [pyalarmdotcomajax.devices] Desired: [3] | Current: [3]
2023-06-09 07:18:51.316 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client]
====================[ WEBSOCKET MESSAGE: END ]====================

Although I'm not really sure what the state numbers mean, I'm pretty sure that partition1 is their name for my house. So me arming away appears to have caused this event to show up in the integration - but for some reason it still didn't show up as the new state until 10 minutes later when "getting all devices" occurred. (There were several Sending keep alive signal. entries in that time.)

So basically, it works in the end, but the websocket listener seems to have ignored the partition1 becoming armed message for some reason.

BTW: I still have a fair amount of noise from the energy meter currently being blocked by my provider plus some Tapo device issue, so reading the logs is pretty messy for me.

@elahd
Copy link
Collaborator

elahd commented Jun 9, 2023

@catellie

  • The debug logs are verbose. It's a pain to look through. Sorry about that!
  • State 3 is arm away.
  • You are missing one key message between WEBSOCKET MESSAGE: BEGIN and WEBSOCKET MESSAGE: END. Below is what you should expect to see in the logs when arming/disarming:

Arm away flow initiated:

2023-06-09 20:55:52.128 DEBUG (MainThread) [pyalarmdotcomajax.devices.partition] Calling arm away.

Integration changes partition status in pyalarmdotcomajax's device registry to "armed away":

2023-06-09 20:55:52.128 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got async update for Alarm (999999999-127) from WebSocket message with new {'desiredState': 3}.

Integration receives state change update from pyalarmdotcomajax and changes state in HA to "arming". (Updates to a device trigger updates for all sub-entities.)

2023-06-09 20:55:52.131 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Alarm Control Panel Alarm (999999999-127): arming
2023-06-09 20:55:52.131 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Malfunction (999999999-127): off
2023-06-09 20:55:52.131 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Battery (999999999-127): off
2023-06-09 20:55:52.132 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Debug (999999999-127): None

Pyalarmdotcomajax sends arm away command to Alarm.com and waits for a synchronous response from the server:

2023-06-09 20:55:52.132 INFO (MainThread) [pyalarmdotcomajax] Sending Command.ARM_AWAY to Alarm.com.
2023-06-09 20:55:52.133 DEBUG (MainThread) [pyalarmdotcomajax] Url https://www.alarm.com/web/api/devices/partitions/999999999-127/armAway

While waiting for a synchronous response, pyalarmdotcomajax gets an asynchronous WebSocket message indicating that the alarm has been armed. (EventType 10 = armed away):

2023-06-09 20:55:53.211 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client] 
====================[ WEBSOCKET MESSAGE: BEGIN ]====================
{
    "EventDateUtc": "2023-06-09T20:55:52.989Z",
    "UnitId": 999999999,
    "DeviceId": 127,
    "EventType": 10,
    "EventValue": -234234234.0,
    "CorrelatedId": null,
    "QstringForExtraData": "lid=77777777&ew=&ew_contact_user_type=0",
    "DeviceType": -1
}
2023-06-09 20:55:53.212 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] WebSocket Message Type: Event

The below is the same pattern at the earlier arming change, except that we're changing the state to armed away. Your post is missing the "Updated Device..." logs, indicating that the integration never got a notice from the library.

2023-06-09 20:55:53.212 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got async update for Alarm (999999999-127) from WebSocket message with new {'state': 3, 'desiredState': 3}.
2023-06-09 20:55:53.215 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Alarm Control Panel Alarm (999999999-127): armed_away
2023-06-09 20:55:53.216 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Malfunction (999999999-127): off
2023-06-09 20:55:53.216 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Battery (999999999-127): off
2023-06-09 20:55:53.217 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Debug (999999999-127): None
2023-06-09 20:55:53.217 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client] 
====================[ WEBSOCKET MESSAGE: END ]====================

Pyalarmdotcomajax gets a (synchronous) response from the arm away request. Ignore the "async" in the "Got async update" message -- it's a synchronous update.

2023-06-09 20:55:54.184 DEBUG (MainThread) [pyalarmdotcomajax] Response from Alarm.com 200
2023-06-09 20:55:54.185 DEBUG (MainThread) [pyalarmdotcomajax] 
==============================
Server Response:
{"data": {"id": "999999999-127", "type": "devices/partition", "attributes": {"partitionId": 1, "state": 3, "desiredState": 3, "extendedArmingOptions": {"Disarmed": [], "ArmedStay": [2, 1, 0, 4], "ArmedAway": [2, 1, 0, 4], "ArmedNight": []}, "invalidExtendedArmingOptions": {"Disarmed": [], "ArmedStay": [], "ArmedAway": [], "ArmedNight": []}, "needsClearIssuesPrompt": false, "canEnableAlexa": false, "isAlexaEnabled": false, "canAccessPanelWifi": true, "canBypassSensorWhenArmed": false, "dealerEnforcesForceBypass": false, "hasSensorInTroubleCondition": false, "hasOpenBypassableSensors": false, "hideForceBypass": false, "sensorNamingFormat": 3, "managedDeviceType": 11, "canBeRenamed": true, "canAccessWebSettings": true, "canAccessAppSettings": true, "webSettings": 1002, "hasState": true, "canBeDeleted": false, "canAccessTroubleshootingWizard": false, "troubleshootingWizard": null, "addDeviceResource": 0, "canBeAssociatedToVideoDevice": false, "associatedCameraDeviceIds": {}, "macAddress": "", "manufacturer": "", "isAssignedToCareReceiver": false, "isOAuth": false, "isZWave": false, "supportsCommandClassBasic": false, "isMalfunctioning": false, "canBeSaved": true, "canChangeDescription": true, "description": "Alarm", "deviceModelId": 9609, "canConfirmStateChange": true, "canReceiveCommands": true, "remoteCommandsEnabled": true, "hasPermissionToChangeState": true, "deviceIcon": {"icon": 186}, "batteryLevelNull": null, "lowBattery": false, "criticalBattery": false}, "relationships": {"sensors": {"data": [{"id": "999999999-14", "type": "devices/sensor"}, {"id": "999999999-26", "type": "devices/sensor"}, {"id": "999999999-23", "type": "devices/sensor"}, {"id": "999999999-22", "type": "devices/sensor"}, {"id": "999999999-5288", "type": "devices/sensor"}, {"id": "999999999-5258", "type": "devices/sensor"}, {"id": "999999999-7", "type": "devices/sensor"}, {"id": "999999999-28", "type": "devices/sensor"}, {"id": "999999999-11", "type": "devices/sensor"}, {"id": "999999999-10", "type": "devices/sensor"}, {"id": "999999999-17", "type": "devices/sensor"}, {"id": "999999999-16", "type": "devices/sensor"}, {"id": "999999999-5285", "type": "devices/sensor"}, {"id": "999999999-31", "type": "devices/sensor"}, {"id": "999999999-30", "type": "devices/sensor"}, {"id": "999999999-4", "type": "devices/sensor"}, {"id": "999999999-3", "type": "devices/sensor"}, {"id": "999999999-5", "type": "devices/sensor"}, {"id": "999999999-6", "type": "devices/sensor"}, {"id": "999999999-24", "type": "devices/sensor"}, {"id": "999999999-9", "type": "devices/sensor"}, {"id": "999999999-8", "type": "devices/sensor"}, {"id": "999999999-25", "type": "devices/sensor"}, {"id": "999999999-33", "type": "devices/sensor"}, {"id": "999999999-229", "type": "devices/sensor"}, {"id": "999999999-1", "type": "devices/sensor"}, {"id": "999999999-12", "type": "devices/sensor"}, {"id": "999999999-13", "type": "devices/sensor"}, {"id": "999999999-27", "type": "devices/sensor"}, {"id": "999999999-15", "type": "devices/sensor"}, {"id": "999999999-18", "type": "devices/sensor"}, {"id": "999999999-21", "type": "devices/sensor"}, {"id": "999999999-19", "type": "devices/sensor"}, {"id": "999999999-20", "type": "devices/sensor"}, {"id": "999999999-5290", "type": "devices/sensor"}], "meta": {"count": "35"}}, "system": {"data": {"id": "88888888", "type": "systems/system"}}, "stateInfo": {"data": {"id": "999999999-127-6", "type": "devices/state-info"}}}}, "included": [], "meta": {"transformer_version": "1.1"}}
==============================
2023-06-09 20:55:54.185 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got async update for Alarm (999999999-127) from user action response with new {'partitionId': 1, 'state': 3, 'desiredState': 3, 'extendedArmingOptions': {'Disarmed': [], 'ArmedStay': [2, 1, 0, 4], 'ArmedAway': [2, 1, 0, 4], 'ArmedNight': []}, 'invalidExtendedArmingOptions': {'Disarmed': [], 'ArmedStay': [], 'ArmedAway': [], 'ArmedNight': []}, 'needsClearIssuesPrompt': False, 'canEnableAlexa': False, 'isAlexaEnabled': False, 'canAccessPanelWifi': True, 'canBypassSensorWhenArmed': False, 'dealerEnforcesForceBypass': False, 'hasSensorInTroubleCondition': False, 'hasOpenBypassableSensors': False, 'hideForceBypass': False, 'sensorNamingFormat': 3, 'managedDeviceType': 11, 'canBeRenamed': True, 'canAccessWebSettings': True, 'canAccessAppSettings': True, 'webSettings': 1002, 'hasState': True, 'canBeDeleted': False, 'canAccessTroubleshootingWizard': False, 'troubleshootingWizard': None, 'addDeviceResource': 0, 'canBeAssociatedToVideoDevice': False, 'associatedCameraDeviceIds': {}, 'macAddress': '', 'manufacturer': '', 'isAssignedToCareReceiver': False, 'isOAuth': False, 'isZWave': False, 'supportsCommandClassBasic': False, 'isMalfunctioning': False, 'canBeSaved': True, 'canChangeDescription': True, 'description': 'Alarm', 'deviceModelId': 9609, 'canConfirmStateChange': True, 'canReceiveCommands': True, 'remoteCommandsEnabled': True, 'hasPermissionToChangeState': True, 'deviceIcon': {'icon': 186}, 'batteryLevelNull': None, 'lowBattery': False, 'criticalBattery': False}.

Integration updates HA entity states:

2023-06-09 20:55:54.185 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Alarm Control Panel Alarm (999999999-127): armed_away
2023-06-09 20:55:54.186 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Malfunction (999999999-127): off
2023-06-09 20:55:54.186 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Battery (999999999-127): off
2023-06-09 20:55:54.186 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Device Alarm Debug (999999999-127): None

The relevant parts of the code that handle this process are (in order):

  1. Partition WebSocket message handler, here, which calls...
  2. async_handle_external_dual_state_change() for the device's representation in pyalarmdotcomajax. This calls async_handle_external_attribute_change() a few lines below, which, here, calls...
  3. All external update callback functions registered with the device. Each entity in Home Assistant registers a callback function with pyalarmdotcomajax to be run when the library receives a state update. That function is _update_device_data(). This is the function that appears to have been skipped in your case.

I'lll add extra tracing code to a dev release for you to test. That should highlight what the problem is. I'll follow up here when it's ready.

@elahd
Copy link
Collaborator

elahd commented Jun 10, 2023

@catellie

I added trace logging to the master branch. If you install master via HACS, you'll see additional logs. Included are:

  1. Logs when the integration registers an update listener with pyalarmdotcomajax:
2023-06-10 01:13:32.288 DEBUG (MainThread) [pyalarmdotcomajax.devices] Registering external update callback for Front Porch (103238342-1200) with Front Porch Light (103238342-1200)
  1. Logs when the integration is notified of a state change:
2023-06-10 01:13:38.901 DEBUG (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Calling external update callback for listener Front Porch Malfunction (103238342-1200) by Front Porch Light (103238342-1200)
  1. A count of how many external update callbacks are registered with every device in pyalarmdotcomajax. This is shown when pyalarmdotcomajax gets an update:
2023-06-10 01:13:38.907 DEBUG (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Front Porch Light (103238342-1200) has 4 external update callbacks.)

I also added version numbers for the integration and library to the message that you see when Home Assistant starts:

===================================================================
ALARMDOTCOM v3.0.5-alpha.1

This is a custom component
If you have any issues with this you need to open an issue here:
https://github.com/pyalarmdotcom/alarmdotcom/issues

pyalarmdotcomajax v0.5.4-alpha.1
===================================================================

elahd added a commit that referenced this issue Jun 10, 2023
elahd added a commit that referenced this issue Jun 10, 2023
* Addresses issues with state update propagation and diagnostic entity names.

* Fixes for real-time notifications.

* Fix bug with update interval.

* bump version numbers

* Fixes issue with devices reporting unavialable when integration loads.

* Added tracing for #288
@catellie
Copy link

catellie commented Jun 10, 2023

@elahd the newest I can see to download, even with beta turned on its 3.0.4, so now I'm on master 5162e35 🤞

@catellie
Copy link

@elahd I've now let it run for a while and comparing logs with what I do and what I see in Home Assistant UI Logbook.

  • One basic thing: It appears that may door sensor information do not show up in the UI Logbook while the motion sensors (and partions) do. Both kinds show up on the websockets logfile trace so presumably this is intentional?
  • Also, I've not quite figured out the timestamps in the trace file compared to the UI Logbook - typically what I see in the UI is some 10-20 seconds later than the traces - this makes comparison a bit harder, but typically no big deal.
  • With the above in mind, the stuff I've compared have mostly made fair sense so far, with one excaption:
====================[ WEBSOCKET MESSAGE: BEGIN ]====================
{
    "EventDateUtc": "2023-06-10T09:14:30.889Z",
    "UnitId": REDACTED,
    "DeviceId": 127,
    "EventType": 8,
    "EventValue": 1.0,
    "CorrelatedId": 0,
    "QstringForExtraData": "ew=REDACTED&ew_contact_user_type=0&ew_group_id=0&ew_contact_id=REDACTED",
    "DeviceType": -1
}
2023-06-10 11:14:31.098 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] WebSocket Message Type: Event
2023-06-10 11:14:31.098 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got update for partition1 (100787381-127) from WebSocket message with new {'state': 1, 'desiredState': 1}.
2023-06-10 11:14:31.098 DEBUG (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices partition1 (REDACTED) has 0 external update callbacks.)
2023-06-10 11:14:31.099 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client]
====================[ WEBSOCKET MESSAGE: END ]====================

(and a very similar one with state 2 just before) I think this one is from when I did a short "ARM HOME" / "DISARM" on my entrance panel, but it never showed up in the HA UI.

Related to your extra logs points above:

  1. I see these base ones in my list, but there are also many variants that are labeled with Malfunction/Battery/Debug. Intentional or not?
2023-06-10 07:58:56.471 Hemlarm Garda REDACTED with partition1 REDACTED
2023-06-10 07:58:56.478 Altandörr REDACTED with Altandörr REDACTED
2023-06-10 07:58:56.480 Entredörr REDACTED with Entredörr REDACTED
2023-06-10 07:58:56.481 Källardörr REDACTED with Källardörr REDACTED
2023-06-10 07:58:56.482 Övervåning REDACTED with Övervåning REDACTED
2023-06-10 07:58:56.483 Panel Glass Break REDACTED with Panel Glass Break REDACTED
2023-06-10 07:58:56.483 Vardagsrum REDACTED with Vardagsrum REDACTED
2023-06-10 07:58:56.491 Switch REDACTED with Switch REDACTED
2023-06-10 07:58:56.491 Köksfönster REDACTED with Köksfönster REDACTED
2023-06-10 07:58:56.492 Dimmer-relay REDACTED with Dimmer-relay REDACTED
  1. I see no logs with Calling external update callback from pyalarmdotcomajax.devices - only registering and initializing

  2. Here are the external backs extracter from my logs (trimmed down for readability):

2023-06-10 09:30:58.376 pyalarmdotcomajax.devices Övervåning REDACTED has 0 external update callbacks.)
2023-06-10 10:10:50.954 pyalarmdotcomajax.devices Övervåning REDACTED has 0 external update callbacks.)
2023-06-10 10:26:49.655 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 10:56:51.058 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 11:08:49.068 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 11:09:12.354 pyalarmdotcomajax.devices Övervåning REDACTED has 0 external update callbacks.)
2023-06-10 11:14:24.405 pyalarmdotcomajax.devices partition1 REDACTED has 0 external update callbacks.)
2023-06-10 11:14:31.098 pyalarmdotcomajax.devices partition1 REDACTED has 0 external update callbacks.)
2023-06-10 11:44:02.754 pyalarmdotcomajax.devices Övervåning REDACTED has 0 external update callbacks.)
2023-06-10 12:20:18.950 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 12:28:55.509 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 12:58:59.349 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 13:26:45.028 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 13:27:54.291 pyalarmdotcomajax.devices partition1 REDACTED has 0 external update callbacks.)
2023-06-10 13:28:00.985 pyalarmdotcomajax.devices Entredörr REDACTED has 0 external update callbacks.)
2023-06-10 13:28:00.985 pyalarmdotcomajax.devices Entredörr REDACTED has 0 external update callbacks.)
2023-06-10 13:47:46.853 pyalarmdotcomajax.devices partition1 REDACTED has 0 external update callbacks.)
2023-06-10 13:56:50.954 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 13:58:56.784 pyalarmdotcomajax.devices Entredörr REDACTED has 0 external update callbacks.)
2023-06-10 13:58:56.784 pyalarmdotcomajax.devices Entredörr REDACTED has 0 external update callbacks.)
2023-06-10 13:58:57.758 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)
2023-06-10 15:02:03.004 pyalarmdotcomajax.devices Vardagsrum REDACTED has 0 external update callbacks.)

The timings here make fair sense to when things HAVE happened: For example the partition1 arm home/disarm at 11:14 and later 13:27 just before Entredörr (Front door) opens/closes (but leave no trace in the Logbook) and then disarm again at 13:47 (this one was automatic, so it makes snse that the door was opened later at 13:58).

Also, here is the blurb:

ALARMDOTCOM v3.0.5-alpha.1

This is a custom component
If you have any issues with this you need to open an issue here:
https://github.com/pyalarmdotcom/alarmdotcom/issues

pyalarmdotcomajax v0.5.4-alpha.1

As always, let me know if you need more details / Jonas

@elahd
Copy link
Collaborator

elahd commented Jun 10, 2023

Thanks, that's really helpful. Now I need to figure out why external update callbacks wouldn't register. Registration happens when the device is added to hass, either after integration config or on boot.

Can you tell me again which operating system, Python version, and Home Assistant version you have installed? You can check your Python version in the command line using python --version (if that doesn't work, python3 --version).

@catellie
Copy link

catellie commented Jun 10, 2023 via email

@catellie
Copy link

BTW: If it wasn't obvious from my last message, I'm on Python 3.11.3
The container I run is:
6cdc9d02defe ghcr.io/home-assistant/home-assistant:latest "/init" 2 days ago Up 2 days homeassistant
Which apparently is based on Alpine Linux 3.18 and run this kernel:
Linux version 4.15.0-208-generic (buildd@lcy02-amd64-061) (gcc version 7.5.0 (Ubuntu 7.5.0-3ubuntu1~18.04)) #220-Ubuntu SMP Mon Mar 20 14:26:46 UTC 2023

It should hardly matter, but for the record the host is running 32 bit Ubuntu 18.04.

@dstanchfield
Copy link
Contributor

Set the polling to 900 seconds and restart HA.

So, I did this and was fairly surprised to see the door status update in ~real time as promised. I did not previously think these updated at all because of the long polling time (I have left this at 900 seconds). Is polling happening very frequently during this first 15 minute period?

So for that first 15 minute period, websocket events properly propagate their way into HA. That first polling at 15 minutes breaks the event propagation, and from there on updates in HA to device states rely solely on the polling. With websockets correctly passing events, that poll interval could really be in the hours, and events would still arrive in realtime.

I just submitted a pull request to show where is bug is.

@ghds514
Copy link

ghds514 commented Jan 24, 2024

Got it, thanks.

@dstanchfield
Copy link
Contributor

Yeah, no, my system did NOT like that at all. I got only about 2 real-time updates, then nothing at all in either HA OR the Android app. I stood here until my toes froze with the door open and no update at all. I'll keep testing, but I'm not getting consistency so far at all, even in the first 15 min after making the change.

Oh man, you were risking life and literally limb to test that for me, hahaha. Sorry! Really strange what you are seeing though. Websockets are definitely broken for you, and your relying purely on that 10s poll.

@TheWebMachine
Copy link

TheWebMachine commented Jan 24, 2024

On the plus side, it woke me up! haha

I'll point out one thing that shouldn't make any difference, but I'm the A-hole if I'm wrong and don't mention it. My system was installed and is monitored by ADT. Of course, it's all just rebranded Alarmdotcom equipment using adc's cloud all the same. I have to make some system changes via alarmdotcom that are simply not exposed on ADT's site, but it all phones home the same, as best I can tell comparing my own logs to first-party customers.

@catellie
Copy link

catellie commented Jan 24, 2024

What door sensors do you have? Perhaps they are being reported differently within alarmdotcom than mine/others that are working.

My sensor certainly look different, but I could not figure out the model/brand myself, so I've asked my installer guy now - will hopefully come back soon. For now here is a picture:

image

(No banana for scale, but the larger part is about 6.5cm wide while the smaller one is about 4cm)
Still, I would assume we can compare the websocket data to see what is different. Here is mine:

{
    "EventDateUtc": "2024-01-24T16:14:52.896Z",
    "UnitId": 100787381,
    "DeviceId": 3,
    "EventType": 100,
    "EventValue": 0.0,
    "CorrelatedId": null,
    "QstringForExtraData": null,
    "DeviceType": 1
}

Presumably the event type 100 is the important part? A few lines down from that it appears that this is converted to two events (one for open and one for close): [I've trimmed time stamps and prefixes for readability]

WebSocket Message Type: Event
Got update for Entredörr (100787381-3) from WebSocket message with new {'state': 2, 'desiredState': 2}.
Got update for Entredörr (100787381-3) from WebSocket message with new {'state': 1, 'desiredState': 1}.

So, "Entredörr" is Swedish for "Front door", does your door also produce a double event of 2 and 1 from a 100 event type - IIRC 100 is the event for "OpenAndClose". (Looking around the trace file this sensor comes with 3 more attributes: "Malfunction", "Battery" and "Debug" - if that helps at all?)

Best / Jonas

@catellie
Copy link

@TheWebMachine apparently my sensor is a somewhat older version of this "Tyco Visonic":
https://www.visonic.com/Products/Zigbee-based-detectors/zigbee-intrusion-detector/magnetic-door-window-sensor-mct-350

@elahd
Copy link
Collaborator

elahd commented Feb 8, 2024

v3.0.13 contains @dstanchfield's fix. Thanks for doing the heavy lifting on this one.

I'm almost done with a complete rebuild of pyalarmdotcomajax. The new code is cleaner and addresses the structural issues that made the current version unwieldy. Current progress is in the refactor-2024 branch. Pull/push updates are working, as are commands for the device categories that I can access.

I'll put together a CLI and will post back here when it's ready for testing.

@catellie
Copy link

catellie commented Feb 8, 2024

v3.0.13 contains @dstanchfield's fix.
[...]
Pull/push updates are working, as are commands for the device categories that I can access.

I installed it earlier today, and lo&behold: my door events registered correctly when I came home! (A double open+close the same second)
Time will tell whether this is stable (it has worked on and off in the past), but this is really promising...

Great work guys / Jonas

@ghds514
Copy link

ghds514 commented Feb 9, 2024

The whole thing is working very impressively for me since installing this latest update. Very appreciative of the work of those who have made this happen.

@Raul-7-7
Copy link

Raul-7-7 commented Feb 9, 2024

@ghds514 @catellie
Hey guys, do you mind sharing your setting? What is your pull frequency? I am on the latest and it delayed by about 10 min.
Cheers

@ghds514
Copy link

ghds514 commented Feb 9, 2024

My polling remains at 900 seconds (Update Interval) and Websocket Reconnect Timeout is 300 seconds. The fix referred to above in 3.0.13 apparently addresses an issue with websockets and it is this that is allowing for instantaneous updates.

There is some chance that the provider you are with has a bearing on this. I was previously with ADT (which later became Telus in Canada) and this system was never so efficient, and degraded to barely-reliable and then disabled over time. Since switching to a "vanilla" alarm.com provider, it is working fantastically. It is therefore possible (or to some extent, certain in Telus' case at least) that some providers are applying layers that limit functionality of the alarm.com service.

@Raul-7-7
Copy link

Thanks @ghds514
Must be that then, I am with Telus actually! if I set it to 900, it updates every 15 min ! I changed it to 15 seconds and this is good enough for me, but not live :(
I had it on 15 before this update and so far Telus has not complained!

@ghds514
Copy link

ghds514 commented Feb 10, 2024

I moved from Telus because they are forcing migration to a proprietary login:

#357

@pdobrien3
Copy link

door open events seem to take a while to update for me. Close events are almost instantaneous. Seems weird one is quick while the other isn't.

@Raul-7-7
Copy link

@pdobrien3 who is your provider? if you login to Alarm.com and open a window, does it update there instantly?

@sspaul1976
Copy link

sspaul1976 commented Feb 11, 2024 via email

@pdobrien3
Copy link

@pdobrien3 who is your provider? if you login to Alarm.com and open a window, does it update there instantly?

The state changes in Home Assistant seem to be consistent with changes in the alarm.com app. Maybe it is time for a service provider change.

@catellie
Copy link

catellie commented Feb 12, 2024

FYI: My context is still looking stable (3+ days into the current release). I'd say this is now in the state I had expected Alarm.com to provide me with - assuming their local sales guy had known what he was talking about... So thumbs up for this!
In reality, I can't say I really needed the door states to work for any of my automations, the movement sensor have been good enough for me, it was just annoying that it appeared to work for 24 hours and then stopped in the past.

@pdobrien3
Copy link

anyone else noticing two new states between armed_home/armed_away and disarmed? I mow seem to have arming and disarming. Through me for a loop for a hot minute as I have to: and from: defined. Wondering if this is a software or alarm.com thing

@TheWebMachine
Copy link

'Arming' and 'Disarming' are intermediate states presented by the integration when you send an arm or disarm command from the integration to ADC, as a confirmation that the command was sent and is pending. Then, once ADC processes the command, the actual state changes to Armed [Home|Away] or Disarmed, and that is picked up by the integration and shown as such.

You won't see 'Arming' or 'Disarming' statuses from the Integration if you do arm/disarm from ADC or the alarm panel directly.

@TheWebMachine
Copy link

TheWebMachine commented Feb 14, 2024

Through me for a loop for a hot minute as I have to: and from: defined.

How long are you in 'Arming' or 'Disarming' state before you get 'undefined?' Can you show your history for the panel in HA like this (note that 'Arming' and 'Disarming' states don't show in History at all):

Screenshot_20240214_045020_Home Assistant

As you can see, I am getting 'unavailable' state every hour or so, which may also be what you are seeing. I suspect there is something timing out. I have Update Interval set to 10s and Websocket Reconnect Timeout set to 300s.

@pdobrien3
Copy link

I am seeing arming/disarming state changes in the text part of history, not the bar graph part, but they are so quick they might be there and hard to see. My arming/disarming states seem to last between 1 and 3 seconds

@ElJefeClicko
Copy link

I changed it to 15 seconds and this is good enough for me, but not live :( I had it on 15 before this update and so far Telus has not complained!

Good to know 15 seconds is working without trouble. 5 definitely got Alarm.com's attention, and I received a warning email.

@Raul-7-7
Copy link

@ElJefeClicko I am with Telus as well, I am on 900. Have you tried this:

  • Have your SmartSecurity app open
  • Open a Door or Window
  • Does the status update in app? (try refreshing the app by pulling down the screen)
    see how long it takes for the app to show the door/window you opened is actually open.

@ElJefeClicko
Copy link

ElJefeClicko commented Feb 14, 2024 via email

@TheWebMachine
Copy link

I changed it to 15 seconds and this is good enough for me, but not live :( I had it on 15 before this update and so far Telus has not complained!

Good to know 15 seconds is working without trouble. 5 definitely got Alarm.com's attention, and I received a warning email.

5s also got me a warning email, but 10s has been working for me without issue or warning. 10s seems reasonable enough given it often takes up to 10s for ADC to get its act together when something changes at the panel, especially if it has been a while since something has changed (as if the websocket between panel and ADC went stale)...I've watched ADC's cloud take 8-12s to show change when a door or window is open. Arm/disarm from ADC to panel often takes north of 5s, too. Very rarely do I find the integration lagging behind ADC in these latest versions; it's usually ADC lagging behind reality.

@TheWebMachine
Copy link

Unfortunately, status updates are delayed in parallel between Hass and the Alarm.com app for me. That's extra frustrating given that I overhauled my security system to this service specifically for automation, most of which is time-critical.

I have taken to employing the following in my automations to account for this unknown delay while also allowing for a timeout. It has allowed for better flow when the panel is involved.

repeat:
  sequence:
    - delay:
        hours: 0
        minutes: 0
        seconds: 1
        milliseconds: 0
  while:
    - condition: template
      value_template: "{{ repeat.index <= 15 }}"
    - condition: state
      entity_id: alarm_control_panel.panel
      state: armed_home

Screenshot_20240214_130634_Home Assistant

Then I put a final If-then to confirm and act accordingly. The Repeat allows the script to proceed as soon as possible while still waiting and timing out if it doesn't happen in time. (repeat.index is the # of times the loop has run) Then I can send out a notification or TTS to alert of the failure.

@Raul-7-7
Copy link

@ElJefeClicko @TheWebMachine
I had the same issue (app not updating) then I did a trick and it seems to be working
Go to alarm.com --> Notification --> Setup a new notification rule that sends PUSH notification to your mobile device if any sensor you care about is opened.

Now when I open the window (my update is 900 seconds) it is updated in HA in about 5-10 seconds. and Close is instant.
The only downside, you get extra notification!
Cheers,

@catellie
Copy link

catellie commented Feb 27, 2024

For the record: As far as I can tell, my setup still runs smoothly on v3.0.13, so from my perspective, the only remaining (and minor) issue is that I get a complaint mail from my retailer on each restart with "Alert for Sign in from New Device". I would suspect this is because it is expected that the "web browser" the Home Assistant plugin pretends to be doesn't retain the cookie between calls, and hence it regarded as a new login each time? I guess a simple mail filter would handle that, but I prefer not to do that since it might hide an actual bad player... Anyway: great work everyone!

@elahd
Copy link
Collaborator

elahd commented Mar 29, 2024

A new pyalarmdotcomajax version is ready for testing. See #391 if you're able to help. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests