Changes to device states not reflected in Home Assistant

patrickabernathy commented 1 year ago

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 commented 1 year ago

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

ghds514 commented 1 year ago

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 commented 1 year ago

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

lbreggi commented 1 year ago

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

TheWebMachine commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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

TheWebMachine commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

@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.

Actions initiated through Home Assistant may take up to 60 seconds to complete. This includes commands for your alarm, locks, garage doors, etc.
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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

@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 commented 1 year ago

@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):

Partition WebSocket message handler, here, which calls...
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...
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 commented 1 year ago

@catellie

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

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)

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)

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
===================================================================

catellie commented 1 year ago

@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 commented 1 year ago

@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

2) I see no logs with Calling external update callback from pyalarmdotcomajax.devices - only registering and initializing

3) 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 commented 1 year ago

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 commented 1 year ago

I'm out and about for the evening, but basically I'm running the latest (ish) 32bit (don't ask) docker image:

Home Assistant 2023.6.1 Frontend 20230608.0 - latest

I can give more details tomorrow.

Best / Jonas

Den lör 10 juni 2023 17:41Elahd Bar-Shai @.***> skrev:

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 https://developers.home-assistant.io/docs/core/entity/#async_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).

— Reply to this email directly, view it on GitHub https://github.com/pyalarmdotcom/alarmdotcom/issues/288#issuecomment-1585710238, or unsubscribe https://github.com/notifications/unsubscribe-auth/AADZ47LYQIOAENF6WUT56EDXKSIUFANCNFSM6AAAAAAYVUWEVY . You are receiving this because you were mentioned.Message ID: @.***>

catellie commented 1 year ago

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.

catellie commented 1 year ago

Oh, and just to be clear: my block under point 1 above was the list of Registering external update callback that where triggered on HASS boot, but I had trimmed out variants to make it readable, for example my front door had these:

Registering external update callback for Entredörr Battery REDACTED with Entredörr REDACTED
Registering external update callback for Entredörr Debug REDACTED with Entredörr REDACTED
Registering external update callback for Entredörr Malfunction REDACTED with Entredörr REDACTED
Registering external update callback for Entredörr REDACTED with Entredörr REDACTED

I guess the battery/debug/malfunction variants CAN be useful, but the the primary one (here at the bottom) is presumably the one that really needs the listener for instant feedback - I expect the others to be good enough reporting at the occasional full scan?

As far as I can tell, all my devices have all four of these whether I like it or not and the registration log indicates that first all the primary ones are registered, then all the Malfunction, then all the Battery and finally all the Debug - but the devices in each group seem semi-jumbled - in this specific case, partition1 starting each group but my Z-wave devices coming in significantly later in the lists. :shrug: Could this cause some kind of clash that makes it fail?

catellie commented 1 year ago

Side note: I've noticed some HA devices now have "Attributes" showing at the bottom of the info dialog. It would be pretty neat if you were able to expose the battery level that way - currently my front door just shows "DisplayStateText Closed". Also, somewhat strangely, it currently has two Logbook entry that say "Turned off" and "Became unavailable" about an hour after I came home last night - this seems to be the same for all (or at least most) of my alarm.com sensors so I suspect those entries should be ignored.

catellie commented 1 year ago

Further digging: On the positive side, the presence sensors (Vardagsrum and Övervåning in my list above) seem to report "Turned on/off" perfectly still while neither the of the doors (Entredörr and Altandörr) make any sense. Obviously they are different kind of sensors (the doors have what I believe are magnets) so that might affect the details in how they are reported? For kicks, I opened and close the back door and saw this in the logs:

====================[ WEBSOCKET MESSAGE: BEGIN ]====================
{
    "EventDateUtc": "2023-06-11T11:03:39.963Z",
    "UnitId": REDACTED,
    "DeviceId": 4,
    "EventType": 100,
    "EventValue": 0.0,
    "CorrelatedId": null,
    "QstringForExtraData": null,
    "DeviceType": 1
}
2023-06-11 13:03:40.142 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] WebSocket Message Type: Event
2023-06-11 13:03:40.143 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got update for Altandörr (REDACTED) from WebSocket message with new {'state': 2, 'desiredState': 2}.
2023-06-11 13:03:40.143 DEBUG (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Altandörr (REDACTED) has 0 external update callbacks.)
2023-06-11 13:03:40.143 INFO (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Got update for Altandörr (REDACTED) from WebSocket message with new {'state': 1, 'desiredState': 1}.
2023-06-11 13:03:40.143 DEBUG (MainThread) [pyalarmdotcomajax.devices] pyalarmdotcomajax.devices Altandörr (REDACTED) has 0 external update callbacks.)
2023-06-11 13:03:40.143 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client]
====================[ WEBSOCKET MESSAGE: END ]====================

... but still nothing in the Logbook. Just to be on the safe side: I assume you don't care too much about the name? In the json dump the ö character in the name shows up as Altand\u00f6rr which seems to be the correct unicode representation, but there is clearly potential for a mismatch depending on the parser...

[Edit: as far as I can tell, the doors and then presence sensor both toggle between the 1 and 2 state, so for now the only oddity I can detect is the ö characted :shrug: ]

Best / Jonas

elahd commented 1 year ago

@catellie Thanks, this is fantastic detail. I'm pretty sure that we're running into a race condition in which the integration attempts to register update listeners with the pyalarmdotcomajax devices before the devices are fully initialized. I made a few changes to how events are reported from the library to the integration. Instead of pyalarmdotcomajax devices reporting directly to their Home Assistant counterparts, a controller in pyalarmdotcomajax now reports directly to a controller in the integration. The controllers are initialized before any devices and are more reliably present. Can you install the latest master branch and see if you have better results?

catellie commented 1 year ago

@elahd Installed. Have plans for the evening, but will try to check the logs...

catellie commented 1 year ago

@elahd Well, I can already say one thing is better: my front door was correctly registered as opening and closing when I left today! (The two time stamps have the exact same second which is somewhat unlikely, but less important.)

mbhforum commented 1 year ago

I upgraded to 3.0.4 from 3.0.3 Beta. I noticed when we left the house today, my routine didn't arm my Alarm. I went back into the system and had to configure the entity state in the scene back to Away.

catellie commented 1 year ago

@mbhforum That's fairly common for the nonworking listener - sometimes it fixes itself at the next full sync, though. If you feel adventurous using master seems a lot better...

elahd commented 1 year ago

Thanks @catellie. Let me know whether this is looking stable.

@mbhforum: I'm hoping that the fix for @catellie will work for you as well. You can test it out now by installing the master branch through HACS, or hold off for v3.0.5.

catellie commented 1 year ago

@elahd it is still looking pretty good. The only issue I've seen is that all alarmdotcom devices suddenly became unavailable at 9:14 and then repeated the previous state about a minute later. Some kind of reset perhaps? I'll take a look when I'm back home (say in 6+ hours).

Screenshot_20230612-163901

elahd commented 1 year ago

@catellie Devices now only show up as unavailable if the periodic pull refresh fails. The pull script refreshes all devices at once, so they'll all get marked as unavailable if a single poll fails.

Polling retries automatically, but that's a built-in Home Assistant process so I can't tell you much else about it.

Do you see anything about the failure in the logs? This would show up even with debug logging turned off.

With that said, I wouldn't consider this a serious issue as-is since it was able to recover quickly.

catellie commented 1 year ago

@elahd I only had a quick lock (when I picked up my gym bag on the fly), and I was unable to locate the cause, but what I CAN say is that the listeners have not triggered since that 9:14 issue - even though I could see initialization happening just after - perhaps that's the problem? A in duplicate listeners cause breakage. Obviously, I'll dig deeper when I can...

mikesalz commented 1 year ago

Hi @elahd - Sorry, I accidentally posted this in the Closed issue. So reposting here. I installed 3.0.4 yesterday and it did work at first. But today I am getting this:

Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/config/custom_components/alarmdotcom/controller.py", line 155, in _keep_alive return await self.api.keep_alive() # type: ignore ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/init.py", line 745, in keep_alive await self._reload_session_context() File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/init.py", line 770, in _reload_session_context raise UnexpectedResponse(f"Failed to reload session context. Response: {json_rsp}") pyalarmdotcomajax.exceptions.UnexpectedResponse: Failed to reload session context. Response: {'errors': [{'status': '403', 'detail': 'NotAllowed', 'code': 403}]}

catellie commented 1 year ago

@elahd I believe I've now found the error. All is fine at 2023-06-12 09:12:29 (assuming [pyalarmdotcomajax.devices] Initialized .... all devices pretty often is considered "normal"). Then:

2023-06-12 09:13:59.221 DEBUG (MainThread) [custom_components.alarmdotcom.controller] custom_components.alarmdotcom.controller: Requesting update from Alarm.com.
2023-06-12 09:13:59.221 DEBUG (MainThread) [pyalarmdotcomajax] Calling update on Alarm.com
2023-06-12 09:13:59.661 DEBUG (MainThread) [pyalarmdotcomajax] Trouble condition response:
{'errors': [{'status': '403', 'detail': 'NotAllowed', 'code': 403}]}
2023-06-12 09:13:59.661 DEBUG (MainThread) [pyalarmdotcomajax]
==============================
Server Response:
{"errors": [{"status": "403", "detail": "NotAllowed", "code": 403}]}
==============================
2023-06-12 09:13:59.661 DEBUG (MainThread) [pyalarmdotcomajax] pyalarmdotcomajax: Request error. Status: 403. Response: {'errors': [{'status': '403', 'detail': 'NotAllowed', 'code': 403}]}
2023-06-12 09:13:59.663 WARNING (MainThread) [py.warnings] /usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/__init__.py:1219: RuntimeWarning: coroutine 'AlarmController.is_logged_in' was never awaited
  if not self.is_logged_in():

2023-06-12 09:13:59.696 INFO (MainThread) [pyalarmdotcomajax] Getting system data for REDACTED.
2023-06-12 09:14:00.160 DEBUG (MainThread) [pyalarmdotcomajax]
==============================
Server Response:
{"errors": [{"status": "403", "detail": "NotAllowed", "code": 403}]}
==============================
2023-06-12 09:14:00.160 DEBUG (MainThread) [pyalarmdotcomajax] pyalarmdotcomajax: Request error. Status: 403. Response: {'errors': [{'status': '403', 'detail': 'NotAllowed', 'code': 403}]}
2023-06-12 09:14:00.160 ERROR (MainThread) [pyalarmdotcomajax] Failed to get system metadata.
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/__init__.py", line 1061, in _async_get_system
    return [json_rsp["data"]]
            ~~~~~~~~^^^^^^^^
KeyError: 'data'
2023-06-12 09:14:00.162 ERROR (MainThread) [custom_components.alarmdotcom.controller] Error fetching REDACTED data:
2023-06-12 09:14:00.163 DEBUG (MainThread) [custom_components.alarmdotcom.controller] Finished fetching REDACTED data in 0.943 seconds (success: False)

Then there seems to be a full update of all my devices and after that:

2023-06-12 09:14:06.259 DEBUG (MainThread) [pyalarmdotcomajax] Sending keep alive signal. Time until session context refresh: ~ 12 minutes.
2023-06-12 09:14:06.768 DEBUG (MainThread) [pyalarmdotcomajax] Session expired.
2023-06-12 09:14:06.768 INFO (MainThread) [pyalarmdotcomajax] User session expired. Logging back in.
2023-06-12 09:14:06.768 DEBUG (MainThread) [pyalarmdotcomajax] Attempting to log in to Alarm.com
2023-06-12 09:14:07.502 DEBUG (MainThread) [pyalarmdotcomajax] Response status from Alarm.com: 200
2023-06-12 09:14:08.917 DEBUG (MainThread) [pyalarmdotcomajax] Logged in to Alarm.com.
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] *** START IDENTITY INFO ***
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] Provider: REDACTED
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] User: REDACTED
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] Keep Alive Interval: 780000
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] Keep Alive URL: /web/KeepAlive.aspx
2023-06-12 09:14:09.686 DEBUG (MainThread) [pyalarmdotcomajax] *** END IDENTITY INFO ***
2023-06-12 09:14:10.108 DEBUG (MainThread) [pyalarmdotcomajax]
==============================
Server Response:
{"data": {"id": REDACTED, "type": "twoFactorAuthentication/twoFactorAuthentication", "attributes": {"smsMobileNumber": {"country": "44"}, "email": "REDACTED", "currentDeviceName": "Other", "isCurrentDeviceTrusted": false, "selectedTypeOf2FA": 0, "enabledTwoFactorTypes": 0, "valid2FAPermissions\
": [1, 4], "canReset2FA": false, "showSuggestedSetup": false, "canSkipSuggestedSetup": false}}, "meta": {"transformer_version": "1.1"}}
==============================
2023-06-12 09:15:06.260 DEBUG (MainThread) [pyalarmdotcomajax] Sending keep alive signal. Time until session context refresh: ~ 12 minutes.
2023-06-12 09:15:30.220 DEBUG (MainThread) [custom_components.alarmdotcom.controller] custom_components.alarmdotcom.controller: Requesting update from Alarm.com.
2023-06-12 09:15:30.220 DEBUG (MainThread) [pyalarmdotcomajax] Calling update on Alarm.com
2023-06-12 09:15:30.653 DEBUG (MainThread) [pyalarmdotcomajax] Trouble condition response:
{'data': [], 'included': [], 'meta': {'transformer_version': '1.1'}}
2023-06-12 09:15:30.653 DEBUG (MainThread) [pyalarmdotcomajax]
==============================
Server Response:
{"data": [], "included": [], "meta": {"transformer_version": "1.1"}}
==============================
2023-06-12 09:15:30.653 INFO (MainThread) [pyalarmdotcomajax] Getting system data for REDACTED.
2023-06-12 09:15:31.183 DEBUG (MainThread) [pyalarmdotcomajax]
==============================

There is plenty of Initialized ... after that but the only triggering external state update callback for line is from when I manually clicked on one of the lamps that are connected though the alarm (Köksfönster) listening no sensor updates at all.

I've not (YET!) gone into further details (I can if you think it helps!), but this APPEARS to strike now and then: The logs were "stable" in the above state most of the day, but from around 17:18 (this is around the time I was picking up my gym bag) until 21:26 the Became unavailable triggered a handful or so times for no apparent reason.

If it matters I can leave it like this for a while, but I think it makes more sense to restart and see if I can find a more clear pattern.

Best / Jonas

elahd commented 1 year ago

@mikesalz @catellie

Looks like you're both running into issues with recovery code that tries to log the user back in when the session expires. I fixed and re-uploaded. If you install master again via HACS you'll have the update.

mikesalz commented 1 year ago

Thanks @elahd ! Dumb question, but do you literally mean install "master" or should we reinstall v3.0.4?

elahd commented 1 year ago

Literally install master. That'll give you v3.0.5-alpha.3.

mbhforum commented 1 year ago

Thanks @catellie. Let me know whether this is looking stable.

@mbhforum: I'm hoping that the fix for @catellie will work for you as well. You can test it out now by installing the master branch through HACS, or hold off for v3.0.5.

Hi - I upgraded to Master and my alarm states are not triggering from my automation//scenes. Below is evidence the scene ran, but nothing in the actual alarm.com logs.I just enabled debugging logs and will report back. This seems like a different issue than state (which appears to be good now).

catellie commented 1 year ago

@mbhforum for now I'd suggest you stick to getting the "listening" for stuff happening in alarmdotcom - until we get that part stable, I think it is pretty optimistic to hook in automations on top... YMMV.

@elahd I've found two significant suspects today. First this one some 15 minutes after I left and armed the house:

2023-06-13 07:36:37.113 ERROR (MainThread) [pyalarmdotcomajax.websockets.client] Unexpected WebSocket error
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/client.py", line 138, in _connect
    await self._async_handle_message(json.loads(msg.data))
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/client.py", line 176, in _async_handle_message
    message = process_raw_message(raw_message, self._device_registry)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/messages.py", line 44, in process_raw_message
    return EventMessage(message, device)
                                 ^^^^^^
UnboundLocalError: cannot access local variable 'device' where it is not associated with a value
2023-06-13 07:36:37.116 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client] Websocket WebSocketState.DISCONNECTED

I suspect this effectively killed the listening? At least I see no event logs after I left (like for instance when I returned back and opened the door)

Later in the evening (this is ~5 minutes after I came back home after picking up a package) - I had still not had time to look at logs:

[successful fetch of SYSTEM data just milliseconds before]
2023-06-13 17:54:59.433 INFO (MainThread) [pyalarmdotcomajax] Getting all devices in REDACTED.
2023-06-13 17:55:30.827 ERROR (MainThread) [custom_components.alarmdotcom.controller] Error requesting REDACTED data: Cannot connect to host www.alarm.com:443 ssl:default [Connection reset by peer]
2023-06-13 17:55:30.828 DEBUG (MainThread) [custom_components.alarmdotcom.controller] Finished fetching REDACTED data in 32.398 seconds (success: False)
2023-06-13 17:55:30.828 INFO (MainThread) [custom_components.alarmdotcom.base_device] Updated Alarm Control Panel Hemlarm Garda (REDACTED): disarmed
[... all other devices...]

If I read this right it claims to have tried for 32+ seconds to get all devices, and calls it success: False but in the very same microsecond has state information about every single device. So either this unsuccessful call had a fair bit of data, or perhaps there was a race with parallel calls? Or are the time stamps not at all to be trusted?

As I mentioned, at this stage I see no logs at all from any listeners, just active polling. For the record: I'll just restart this now, still on master.

Best / Jonas

elahd commented 1 year ago

The timestamps can be trusted.

That first issue is a bug that caused websocket monitoring to fail when a message came in for an unsupported device. That's now fixed in master.

The second error is just a connection error from Python's aiohttp library. Home Assistant couldn't connect to Alarm.com for some reason. I added more logging to master to give us more context. Also, it's possible that connection errors permanently knock websocket monitoring offline.

Please update when you have a chance.

catellie commented 1 year ago

@elahd good to hear. Installing now...

catellie commented 1 year ago

@elahd Well, this time around it only seems to have run for less than 20 mins before this happened:

2023-06-14 07:48:40.737 ERROR (MainThread) [pyalarmdotcomajax.websockets.client] Unexpected WebSocket error
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/client.py", line 138, in _connect
    await self._async_handle_message(json.loads(msg.data))
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/client.py", line 176, in _async_handle_message
    message = process_raw_message(raw_message, self._device_registry)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pyalarmdotcomajax/websockets/messages.py", line 44, in process_raw_message
    return EventMessage(message, device)
                                 ^^^^^^
UnboundLocalError: cannot access local variable 'device' where it is not associated with a value
2023-06-14 07:48:40.740 DEBUG (MainThread) [pyalarmdotcomajax.websockets.client] Websocket WebSocketState.DISCONNECTED

However, I'm not entirely sure this is correct as I'm 99.999% sure I selected and restarted master, but now that I double checked your new header with more versioning is not in the logs and under HACS it is listed as v3.0.4. For good measure I installed it once again with identical results. Hence I suspect master somehow got rolled back?!? (Technically is makes sense since the error looks rather familiar.)

Or is my HA installation utterly confused? / Jonas :thinking:

elahd commented 1 year ago

It's not your HA instance. It's failing in a weird way. My last change was an attempt to prevent the UnboundLocalError from appearing. I just uploaded new code that catches UnboundLocalError and shows more detail around the message itself. That code is now in master.

Alternatively, are you able to scroll up in the logs and share the message that triggered this error? What kind of device is it for?

catellie commented 1 year ago

Now I'm on dd326b0 :tada:

I still had my editor around with that buffer. Scrolling past a for number of Energie errors hope this is the one that cause the problem above:

====================[ WEBSOCKET MESSAGE: BEGIN ]====================
{
    "EventDateUtc": "2023-06-14T05:48:10.003Z",
    "UnitId": REDAC,
    "DeviceId": TED,
    "EventType": 403,
    "EventValue": 2175683.0,
    "CorrelatedId": 0,
    "QstringForExtraData": "fence_id=2175683",
    "DeviceType": -1
}
2023-06-14 07:48:10.735 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] Got a message for unknown device REDACTED:
{
    "EventDateUtc": "2023-06-14T05:48:10.003Z",
    "UnitId": REDAC,
    "DeviceId": TED,
    "EventType": 403,
    "EventValue": 2175683.0,
    "CorrelatedId": 0,
    "QstringForExtraData": "fence_id=2175683",
    "DeviceType": -1
}
2023-06-14 07:48:10.735 DEBUG (MainThread) [pyalarmdotcomajax.websockets.messages] WebSocket Message Type: Event

Presumably 403 still indicates FORBIDDEN? The id (that I have redacted) points to that it is a geolocation/geo-device (clearly under geoDevices) when it is picked up correctly in the system data. The fence_id bit sort of indicates that it MIGHT relate the position of my phone vs home? IIRC, there is a flag to auto-disarm when you approach, right?

Perhaps the API can not provide locations for regulation reasons?

elahd commented 1 year ago

Ok, just made another fix. Try installing master once more.

403 isn't on the list of known event types, but I don't think that it means forbidden. I haven't seen that these error codes line up with HTTP status codes.

If we're still seeing failures after this attempt, I'll try building more robust testing around this feature to iron out the issues locally.

catellie commented 1 year ago

Cool, I'm now on 887365c

mikesalz commented 1 year ago

FYI I just tried the latest Master and received this error:

Error setting up entry ADT Security for alarmdotcom Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/config_entries.py", line 387, in async_setup result = await component.async_setup_entry(hass, self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/alarmdotcom/init.py", line 155, in async_setup_entry entity_registry.async_remove(entity_entry.id) File "/usr/src/homeassistant/homeassistant/helpers/entity_registry.py", line 649, in async_remove self.entities.pop(entity_id) File "", line 912, in pop File "/usr/local/lib/python3.11/collections/init.py", line 1124, in getitem raise KeyError(key) KeyError: 'cd94bdb1decc17ab81d843fe6cccc055'

catellie commented 1 year ago

@elahd For me, above mentioned master is still ticking along and both doors and motion detectors are reported seemingly close to perfect (the doors are still opened and closed at the same second, but I can live with that). Also arming/disarming appear to work/be detected correctly. If this holds true for a while longer I'll add some automation on top...

pyalarmdotcom / alarmdotcom

Changes to device states not reflected in Home Assistant #288