Ness DX8/DX16 Alarm

cryptelli · March 18, 2019, 1:09pm

I’ve had to jerry-rig an input_boolean triggered on arming as a way of tracking when it’s armed for my automations which rely on the alarm to function.

Hopefully @nickw444 finds time to troubleshoot the issue since it was working flawlessly before this recent change, especially with the added scan_interval option, if I can provide any further debugging info just let me know.

nickw444 · March 19, 2019, 11:18am

Hi @cryptelli I’m still a bit suspicious about the logs you provided, even though you were able to confirm you are running 0.9.14. It will be very difficult to reproduce and debug the issue without being able to see what data ness-cli is sending to your IP module.

I would expect output similar to the following

DEBUG:nessclient.client:Requesting state update from server (S00, S14)
DEBUG:nessclient.client:Attempting to connect
DEBUG:nessclient.client:Sending payload: '8300360S00E9\r\n'
DEBUG:nessclient.client:Sending payload: '8300360S14E4\r\n'
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
Zone 1 changed to False
Zone 2 changed to False
Zone 3 changed to False
Zone 4 changed to False
Zone 5 changed to False
Zone 6 changed to False
Zone 7 changed to False
Zone 8 changed to False
Zone 9 changed to False
Zone 10 changed to False
Zone 11 changed to False
Zone 12 changed to False
Zone 13 changed to False
Zone 14 changed to False
Zone 15 changed to False
Zone 16 changed to False
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
Alarm state changed to ArmingState.DISARMED

when running the command:

ness-cli --log-level debug events --host alarm.home --port 8234

(Notice the verbose output of what is being sent to the IP module).

Also out of curiosity, and maybe to assist debugging, what is your scan_interval set to at the moment?

cryptelli · March 19, 2019, 1:18pm

I wasn’t really sure what to reply with initially, apart from supply a screen recording to show that it’s honestly not producing the information you’re looking for… when I had a strange idea to run that debug command in the docker container where I had tested the scan_interval which was running HA 0.89.0.dev0 and too my surprise it flipping displayed the same information you’re after, though only upon initial connection the alarm events still aren’t showing any verbose output.

The below debug log was run using HA 0.91.0.dev0 using docker.

root@56f41e46d2dc:/usr/src/app# ness-cli --log-level debug events --host IP --port PORT
DEBUG:nessclient.client:Requesting state update from server (S00, S14)
DEBUG:nessclient.client:Attempting to connect
DEBUG:nessclient.client:Sending payload: '8300360S00E9\r\n'
DEBUG:nessclient.client:Sending payload: '8300360S14E4\r\n'
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
Zone 1 changed to False
Zone 2 changed to False
Zone 3 changed to False
Zone 4 changed to False
Zone 5 changed to False
Zone 6 changed to False
Zone 7 changed to False
Zone 8 changed to False
Zone 9 changed to False
Zone 10 changed to False
Zone 11 changed to False
Zone 12 changed to False
Zone 13 changed to False
Zone 14 changed to False
Zone 15 changed to False
Zone 16 changed to False
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
Alarm state changed to ArmingState.DISARMED
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
DEBUG:nessclient.client:Decoding data: '87008361240101180726033544ae'
DEBUG:nessclient.packet:Decoding bytes: '87008361240101180726033544ae'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 7, 26, 3, 35, 44), 'type': <EventType.ARMED_AWAY: 36>, 'zone': 1, 'area': 1}>
Alarm state changed to ArmingState.ARMING
DEBUG:nessclient.client:Decoding data: '8700036122010118072603354430'
DEBUG:nessclient.packet:Decoding bytes: '8700036122010118072603354430'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 7, 26, 3, 35, 44), 'type': <EventType.EXIT_DELAY_START: 34>, 'zone': 1, 'area': 1}>
Alarm state changed to ArmingState.EXIT_DELAY
DEBUG:nessclient.client:Decoding data: '87008361230001180726033553a1'
DEBUG:nessclient.packet:Decoding bytes: '87008361230001180726033553a1'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 7, 26, 3, 35, 53), 'type': <EventType.EXIT_DELAY_END: 35>, 'zone': 0, 'area': 1}>
Alarm state changed to ArmingState.ARMED
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
Alarm state changed to ArmingState.DISARMED
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>

Don’t know if the above is of any use, but I’m not sure what else I can do from my end to get the results you’re after. Interested to hear your thoughts on this.

I lowered my scan_interval to 2s but haven’t been using it as it wasn’t in 0.89.2 and my attempt to override the default component wasn’t successful, only tested it briefly in the test instance I mentioned above. Figured I’d just wait until it was officially supported in 0.90.0.

cryptelli · March 23, 2019, 2:33am

@nickw444 was the information provided in my previous post enough for you to debug and work on a fix?

Please let me know if I can do anything else to assist.

Yuddy · March 23, 2019, 2:07pm

sensors are working fine but arm home isn’t working for status update. arms the panel but stays as “disarmed”

on latest 0.90.1

logs seem normal. but i’ll keep checking

Yuddy · March 23, 2019, 2:16pm

2019-03-23 21:43:00 DEBUG (MainThread) [nessclient.client] Decoding data: ‘820003601700867e’
2019-03-23 21:43:00 DEBUG (MainThread) [nessclient.packet] Decoding bytes: ‘820003601700867e’
2019-03-23 21:43:00 WARNING (MainThread) [nessclient.client] Failed to decode packet
ValueError: 23 is not a valid RequestID

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/local/lib/python3.7/site-packages/nessclient/client.py”, line 123, in _recv_loop
event = BaseEvent.decode(pkt)
File “/usr/local/lib/python3.7/site-packages/nessclient/event.py”, line 39, in decode
return StatusUpdate.decode(packet)
File “/usr/local/lib/python3.7/site-packages/nessclient/event.py”, line 149, in decode
request_id = StatusUpdate.RequestID(int(packet.data[0:2], 16))
File “/usr/local/lib/python3.7/enum.py”, line 309, in call
return cls.new(cls, value)
File “/usr/local/lib/python3.7/enum.py”, line 561, in new
raise exc
File “/usr/local/lib/python3.7/enum.py”, line 545, in new
result = cls.missing(value)
File “/usr/local/lib/python3.7/enum.py”, line 574, in missing
raise ValueError("%r is not a valid %s" % (value, cls.name))
ValueError: 23 is not a valid RequestID

cryptelli · March 24, 2019, 5:44am

I’ve been conducting some further tests and below are my findings:

Home Assistant Version	`nessclient` Version	Observations (HA UI)	Stable
`0.88.2`	`0.9.9`	Alarm initially disarmed state, after entering pin and using ARM HOME, goes to ‘ARMING’ state, then ‘AWAY’.	Yes
`0.88.2`	`0.9.10`	Alarm initially in the disarmed state, after entering pin and using ARM HOME, goes to `ARMING` then shortly changes to `DISARMED`.	No
`0.88.2`	`0.9.11`	ditto	ditto
`0.88.2`	`0.9.12`	ditto	ditto
`0.88.2`	`0.9.13`	ditto	ditto
`0.88.2`	`0.9.14`	ditto	ditto
`0.99.1`	`0.9.9`	Alarm initially disarmed state, after entering pin and using ARM HOME, goes to ‘ARMING’ state, then ‘AWAY’.	Yes
`0.99.1`	`0.9.10`	Alarm initially in the disarmed state, after entering pin and using ARM HOME, goes to `ARMING` then shortly changes to `DISARMED`.	No
`0.99.1`	`0.9.14`	ditto	ditto

Conclusions:

Based on the above it would appear the issue has crept in from modifications made in nessclient==0.9.10. I hope this can assist you @nickw444 in narrowing down the changes that could have caused this.

I’ve reverted my installation back to 0.9.9 until a fix is released since it was pretty stable and reported the state update reliably.

Yuddy · March 24, 2019, 5:50am

Very good observations

nickw444 · March 24, 2019, 10:53pm

Hi @Yuddy and @cryptelli, thanks for those details. The version breakdown is going to help me a lot in working out what went wrong. I have a feeling it is to do with this change https://github.com/nickw444/nessclient/pull/23. I haven’t had much time lately, but I think I will find some time later this evening to take a deeper look into the problem and potentially solve it.

I’m sure you’ve both posted it above, but to make sure I have it, would you both be able to report your panel version please?

aumatt · March 24, 2019, 11:47pm

@nickw444 Im not super fluent on Python, but the code doesnt look to handle anything other than AREA_1_ARMED or AREA_1_FULLY_ARMED and because in Home it receives a different value it defaults back to disarmed.

If I remember correctly when working on pComms, I had to send 8300360S14E4 after the Exit Delay had ended to capture the correct state of the alarm as I dont think it always sends the status.

I hope that makes sense.

Matt

cryptelli · March 25, 2019, 12:13am

I wasn’t sure where you were at since the debug information didn’t seem to be useful so I’m glad the version breakdown is going to assist in resolving this, however I feel you’ve already narrowed it down successfully.

I updated to nessclient==0.9.14, restored the code from before PR #23 and everything is working as it should.

@cryptelli : 5.7
@Yuddy: 8.6

I test with home (saves me excluding zones while playing around). Under nessclient==0.9.9 it’s able to handle both arming in HOME and AWAY (without reverting to DISARMED) it’s just that HOME is reflected in the UI as ‘Armed away’.

nickw444 · March 25, 2019, 10:09am

Hi @cryptelli I’ve had a further look into the issue and honestly can’t work out why your panel would return an empty response to the S14 request:

8200036014000007

This is what is causing the client to revert back to the DISARMED state. The reason this worked originally is because I had a workaround for the incorrect enum documentation which mean I had to infer the DISARMED state via system status events rather than user interface request responses.

Not to worry though, I have brought back the “inference” functionality until we can find a better solution.

I have put this configuration option behind a flag as it could introduce buginess for currently working setups (like my own). There is potential for setups using this flag to now get stuck/report an ARMED or ARMING state and never return to DISARMED if the panel never emits (or it is not received) a system status event declaring the panel is disarmed. (Unlikely though)

If this solution proves to be successful and applies to particular panel versions (i.e. <5.8 ), then I can introduce a version check at startup and have this functionality auto-configured to avoid needless setup to get a working system. This would use the newly added #36 functionality.

This is the command being sent periodically to the panel (denoted by update_interval), which is what is causing the empty response to be returned described above.

Anyway, that aside, I have released a new pre-release version 0.9.15b1 which can be installed the same as before:

pip install --upgrade 'nessclient[cli]==0.9.15b1'

It would be greatly appreciated if you could test it with the following command, which switches on the state assumption branch:

ness-cli --log-level debug events --host alarm.home --port 8234 --infer-arming-state

Let’s see if this resolves the issue. If this is successful, I will release the fix and bump the version in HA.

cryptelli · March 25, 2019, 10:25am

Again, thank you @nickw444 for trying to iron these kinks out for some of us, it’s greatly appreciated. I’m also at a loss as to why my panel doesn’t respond normally…

I received the notification on GitHub that you’d released 0.9.15b1 and was already upgrading as were posting, thanks for the detailed explanation of the problem and what your plans are to resolve it when this is sorted .

At this stage it’s a 50/50 successful state change, half gets to ‘ARMED’ and reverts to DISARMED after a couple of seconds (slower to revert than before) and the other half doesn’t make it past ARMING before reverting.

I’m running tests now and will post back with the debug messages.

cryptelli · March 25, 2019, 10:30am

Logs using --infer-arming-state flag as requested. Once that last arming update hit the UI reported DISARMED.

EDIT: I know its armed using NIGHT/HOME but the behaviour is the same with AWAY.

DEBUG:nessclient.client:Requesting state update from server (S00, S14)
DEBUG:nessclient.client:Attempting to connect
DEBUG:nessclient.client:Sending payload: '8300360S14E4\r\n'
DEBUG:nessclient.client:Sending payload: '8300360S00E9\r\n'
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
Alarm state changed to ArmingState.DISARMED
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
Zone 1 changed to False
Zone 2 changed to False
Zone 3 changed to False
Zone 4 changed to False
Zone 5 changed to False
Zone 6 changed to False
Zone 7 changed to False
Zone 8 changed to False
Zone 9 changed to False
Zone 10 changed to False
Zone 11 changed to False
Zone 12 changed to False
Zone 13 changed to False
Zone 14 changed to False
Zone 15 changed to False
Zone 16 changed to False
DEBUG:nessclient.client:Decoding data: '87008361270103180801005304f2'
DEBUG:nessclient.packet:Decoding bytes: '87008361270103180801005304f2'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 8, 1, 0, 53, 4), 'type': <EventType.ARMED_NIGHT: 39>, 'zone': 1, 'area': 3}>
Alarm state changed to ArmingState.ARMING
DEBUG:nessclient.client:Decoding data: '8700036122010318080100530576'
DEBUG:nessclient.packet:Decoding bytes: '8700036122010318080100530576'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 8, 1, 0, 53, 5), 'type': <EventType.EXIT_DELAY_START: 34>, 'zone': 1, 'area': 3}>
Alarm state changed to ArmingState.EXIT_DELAY
DEBUG:nessclient.client:Decoding data: '87008361230003180801005314e7'
DEBUG:nessclient.packet:Decoding bytes: '87008361230003180801005314e7'
<SystemStatusEvent {'address': 0, 'timestamp': datetime.datetime(2018, 8, 1, 0, 53, 14), 'type': <EventType.EXIT_DELAY_END: 35>, 'zone': 0, 'area': 3}>
Alarm state changed to ArmingState.ARMED
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>

nickw444 · March 25, 2019, 10:39am

The log you attached appears to end before the next DISARMED was registered. Was there more output? Can you please attach that as it will help me figure out what is causing it to go back to DISARMED.

If that’s all the output there is, then that’s good, since internally the alarm state is still set to ARMED.

cryptelli · March 25, 2019, 10:41am

I like good! No further update reflecting a DISARMED status, just ran it again and when the UI reflected DISARMED the below was output into the console:

EDIT: Just happened to notice that the logs now show a ‘Sending payload’?

DEBUG:nessclient.client:Requesting state update from server (S00, S14)
DEBUG:nessclient.client:Sending payload: '8300360S00E9\r\n'
DEBUG:nessclient.client:Sending payload: '8300360S14E4\r\n'
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>
DEBUG:nessclient.client:Decoding data: '820003600000001b'
DEBUG:nessclient.packet:Decoding bytes: '820003600000001b'
<ZoneUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ZONE_INPUT_UNSEALED: 0>, 'included_zones': []}>
DEBUG:nessclient.client:Decoding data: '8200036014000007'
DEBUG:nessclient.packet:Decoding bytes: '8200036014000007'
<ArmingUpdate {'address': 0, 'timestamp': None, 'request_id': <RequestID.ARMING: 20>, 'status': []}>

nickw444 · March 25, 2019, 10:42am

Ah interesting. Just checking that you’ve restarted home-assistant since upgrading the package within the environment?

cryptelli · March 25, 2019, 10:42am

Sure did .

nickw444 · March 25, 2019, 10:44am

Interesting, I feel like it might be easier to debug this over discord. Are you in the home-assistant discord chat?

cryptelli · March 25, 2019, 10:45am

I was starting to feel the same way, back and fourth on text can only get so far :). I can be, give me 5.