dchesterton / texecom2mqtt-hassio

Home Assistant add-on. Connect to Texecom Premier Elite alarm panels and publish updates to MQTT. Supports arming/disarming as well as zone updates and alarm events.
https://hub.docker.com/r/dchesterton/texecom2mqtt
MIT License
51 stars 9 forks source link

Error on read of alarm when armed and when user logs in #25

Closed cdosrun81 closed 2 years ago

cdosrun81 commented 3 years ago

I should be grateful for some pointers with this. I have this set up on a Home Assistant server that is only using this app to send the MQTT in order that OpenHab then picks up the alarm status and turns on lights etc. I have a Texecom SmartCom in the alarm and also a raspberry PI running SER2NET on COM3. Texecom2mqtt works with either the SmartCom or the Pi but there are a few issues I am having.

The alarm is a Texecom Elite 640

If anyone types their code into a keypad, it kicks texecom2mqtt off with the following:

2021-08-21 12:56:30 - INFO: Hallway quad status changed to Active 2021-08-21 12:56:35 - INFO: Landing quad status changed to Active 2021-08-21 12:56:36 - INFO: Office quad status changed to Secure /snapshot/app/dist/texecom/helpers.js:100 throw new Error("Unknown log event length"); ^ Error: Unknown log event length at Object.parseLogEvent (/snapshot/app/dist/texecom/helpers.js:100:19) at Texecom.parseBuffer (/snapshot/app/dist/texecom/texecom.js:113:58) at Socket.<anonymous> (/snapshot/app/dist/texecom/texecom.js:32:18) at Socket.emit (events.js:315:20) at addChunk (_stream_readable.js:295:12) at readableAddChunk (_stream_readable.js:271:9) at Socket.Readable.push (_stream_readable.js:212:10) at TCP.onStreamRead (internal/stream_base_commons.js:186:23)

In addition, if the alarm is armed (full or part) then the app will not connect to the alarm at all with a similar error.

I have tried with "Enable Attended Download" on and off in Wintex and "Restrict Download when Armed" is not selected but "Download when Part-Armed" is checked.

The alarm does not currently have many sensors and only uses 2 areas but when the app resyncs with it, there is a delay of around 4 minutes. Visible on this excerpt of the log. As this is being used to turn lighting on and off, it is frustrating to have 4 minutes until the lights turn on after someone types in a code.

2021-08-21 12:57:48 - INFO: Fetched Zone 81: Lounge smoke det (Type: Fire; Areas: 1A)
2021-08-21 12:57:49 - INFO: Fetched Zone 82: Lounge quad tech (Type: Guard; Areas: 1A)
2021-08-21 12:57:49 - INFO: Fetched Zone 83: Garden tri-tech (Type: Custom; Areas: 1B)
2021-08-21 13:01:57 - INFO: Updating all zone states...
2021-08-21 13:01:58 - INFO: Updating all area states...
2021-08-21 13:01:59 - INFO: Application ready
2021-08-21 13:02:55 - INFO: Hallway quad status changed to Active

I appreciate that the issue with the delay is having a large panel without many sensors on it but may I ask if there is a mechanism to restrict the scope of the enumeration in zones or areas to reduce this? Alternatively, am I alone in having the alarm kick the serial connection every time a user logs in?

The configuration is as follows: texecom: host: 172.27.87.112 udl_password: 'CODE' mqtt: host: 172.27.81.12 homeassistant: discovery: true areas: [] zones: []

Thank you.

Andrew

dchesterton commented 3 years ago

Hi Andrew,

Thanks for the bug report. I've released a new version which gives more log information if the "Unknown log event length" error occurs. Could you pull the latest version, try to replicate the issue and send me the new output? It should help diagnose the problem.

As for the enumeration, unfortunately there's currently no way to avoid this. Most people are using the app on a 24/48 zone panel where it's pretty quick. I think I'm going to add a feature to cache the zone information so the app starts quicker on larger panels but I can't promise when that will be done.

Thanks, Daniel

cdosrun81 commented 3 years ago

Hi Daniel,

Thank you for your extremely prompt response. I have updated to 1.1.2 and the error below is what appears when using my fob to log into the alarm - no other action taken.

2021-08-23 12:46:54 - INFO: Office quad status changed to Active /snapshot/app/dist/texecom/helpers.js:100 throw new Error(Unknown log event: ${buffer.toString("hex")}); ^ Error: Unknown log event: 53000100ab8bed56ffff000000000000 at Object.parseLogEvent (/snapshot/app/dist/texecom/helpers.js:100:19) at Texecom.parseBuffer (/snapshot/app/dist/texecom/texecom.js:113:58) at Texecom.parseBuffer (/snapshot/app/dist/texecom/texecom.js:143:18) at Socket.<anonymous> (/snapshot/app/dist/texecom/texecom.js:32:18) at Socket.emit (events.js:315:20) at addChunk (_stream_readable.js:295:12) at readableAddChunk (_stream_readable.js:271:9) at Socket.Readable.push (_stream_readable.js:212:10) at TCP.onStreamRead (internal/stream_base_commons.js:186:23)

cdosrun81 commented 3 years ago

Hi Daniel, sorry for leaving two messages in quick succession. I have subsequently logged in as another user and the event this time is 53000200b688ee560100000000000000

The first time I used user 001 and the second time was user 002. I wonder if your code is expecting a 2-digit user reference rather than a 3-digit which would again be a consequence of the larger panel.

Thank you, Andrew

dchesterton commented 3 years ago

Thanks for the debug info, it's really helpful.

I think I see the problem. The documentation states that the log message should be between 8-10 bytes depending on the panel size but for some reason the panel seems to be sending a 16 byte message (where the last 6 bytes are always 0) when you use the prox tag.

I've just pushed an update which I think will fix the issue. Can you pull the latest version again and give it another go?

cdosrun81 commented 3 years ago

Hi Daniel and once again thank you for being so responsive. The app does not now fail when the user logs in but if the alarm is then part-armed, it seems to terminate the connection so the app has to start enumerating again. When the alarm is part-armed, this fails with a buffer our of bounds error. I have some snips below and should be grateful for your thoughts on the issue.

A thought as to the extended reporting you referred to above, the panel is set to Grade3 mode which requires 6-digit passcodes and changes some other settings - is there any indication in the documentation that it would change the messages?

Thank you,

Andrew

`(When re-enumerating once part-armed - the arming process appears to have broken the connection) 2021-08-24 06:45:04 - INFO: Updating all area states... 2021-08-24 06:45:04 - ERROR: Unhandled rejection - RangeError [ERR_BUFFER_OUT_OF_BOUNDS]: Attempt to access memory outside buffer bounds

(on second retry to enumerate whilst part-armed) 2021-08-24 06:45:15 - INFO: Starting texecom2mqtt v1.1.4... 2021-08-24 06:45:15 - INFO: Connected to alarm, sleeping for 1 second... 2021-08-24 06:45:16 - INFO: Connection ready 2021-08-24 06:45:16 - ERROR: Unhandled rejection - Error: Could not fetch serial number

(on third retry to enumerate whilst part-armed) 2021-08-24 06:46:17 - INFO: Fetched Zone 82: Lounge quad tech (Type: Guard; Areas: 1A) 2021-08-24 06:46:17 - INFO: Fetched Zone 83: Garden tri-tech (Type: Custom; Areas: 1B) 2021-08-24 06:49:36 - INFO: Updating all zone states... 2021-08-24 06:49:37 - INFO: Updating all area states... 2021-08-24 06:49:38 - ERROR: Unhandled rejection - RangeError [ERR_BUFFER_OUT_OF_BOUNDS]: Attempt to access memory outside buffer bounds

(When logging in to unset whilst app was still enumerating) 2021-08-24 06:50:00 - INFO: Fetched Zone 2: Office smoke (Type: Fire; Areas: 1A) /snapshot/app/dist/texecom/texecom.js:81 throw new Error(Unexpected start, expected 't', got 0x${headerStart.toString(16)}); ^ Error: Unexpected start, expected 't', got 0x2f at Texecom.parseBuffer (/snapshot/app/dist/texecom/texecom.js:81:19) at Socket. (/snapshot/app/dist/texecom/texecom.js:32:18) at Socket.emit (events.js:315:20) at addChunk (_stream_readable.js:295:12) at readableAddChunk (_stream_readable.js:271:9) at Socket.Readable.push (_stream_readable.js:212:10) at TCP.onStreamRead (internal/stream_base_commons.js:186:23)`

dchesterton commented 3 years ago

I've added a little bit more information around the "ERROR: Unhandled rejection" error.

Can you pull the latest version again and also enable debug logging by adding log: debug to your config file?

cdosrun81 commented 3 years ago

Hi Daniel,

Thank you once again. Updated debug output follows for the failure to enumerate when the alarm is part-armed.

Edit - sorry the code quotes seems to wrap the text awkwardly

021-08-25 07:17:54 - INFO: Fetched Zone 82: Lounge quad tech (Type: Guard; Areas: 1A) 2021-08-25 07:17:54 - INFO: Fetched Zone 83: Garden tri-tech (Type: Custom; Areas: 1B) 2021-08-25 07:18:45 - DEBUG: Command 3 timed out (attempt 1, id: 251). 2021-08-25 07:18:50 - DEBUG: Command 3 timed out (attempt 1, id: 2). 2021-08-25 07:19:03 - DEBUG: Command 3 timed out (attempt 1, id: 32). 2021-08-25 07:20:52 - INFO: Updating all zone states... 2021-08-25 07:20:53 - INFO: Updating all area states... 2021-08-25 07:20:54 - DEBUG: Received area flags for Area 1A: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,0,0,0,1,0,1,1,1,0,0,0,1 2021-08-25 07:20:54 - ERROR: Unhandled rejection - RangeError [ERR_BUFFER_OUT_OF_BOUNDS]: Attempt to access memory outside buffer bounds at boundsError (internal/buffer.js:75:11) at Buffer.readBigUInt64LE (internal/buffer.js:88:5) at Panel.getAreaBitmapFlag (/snapshot/app/dist/panel.js:198:32) at Panel.updateAreaStates (/snapshot/app/dist/panel.js:378:37) at processTicksAndRejections (internal/process/task_queues.js:97:5) at async Panel.loadInitialData (/snapshot/app/dist/panel.js:250:9) at async Panel.start (/snapshot/app/dist/panel.js:239:9) at async /snapshot/app/dist/index.js:73:5 2021-08-25 07:20:54 - DEBUG: Ending socket connection to panel 2021-08-25 07:20:54 - DEBUG: Socket connection to panel ended 2021-08-25 07:20:54 - DEBUG: Publishing to texecom2mqtt/status: offline 2021-08-25 07:20:54 - DEBUG: Panel socket closed

dchesterton commented 3 years ago

I'm still not sure exactly why it's happening but I think I've tracked down where the problem is at least.

I've added some more debug information and released a new version. Could I kindly ask you to download the new version and send the debug log again?

dchesterton commented 2 years ago

This bug was fixed in v1.1.4