ebaauw / homebridge-deconz

Homebridge plugin for deCONZ
Apache License 2.0
135 stars 7 forks source link

NodeJS Issue: Value out of range Error for History Entries #162

Closed brandungskieker closed 11 months ago

brandungskieker commented 11 months ago

Since a few days Homebridge throws an error message that no more history events can be logged for some sensors. Possibly the error is related to NodeJS 18.17.1. I get the following error message:

[7.9.2023, 09:05:03] [deCONZ] OpenClose 5 History: History Entries: error: RangeError: The value of "value" is out of range. It must be >= 0 and <= 4294967295. Received -136632832

Followed by a NodeJS error description.

Does anyone know the problem?

ebaauw commented 11 months ago

What makes you think this could be related to the NodeJS version?

Looks like the history administration has gone wrong. Did you update Homebridge deCONZ from a previous version? Please double check that the file system with the Homebridge user directory isn’t full, and, if running on a Raspberry Pi, that the uSD card isn’t broken.

I cannot see from the message whether this is the history time going wrong or the times opened counter. Would need to see the log with logLevel 2 to debug, but it’s probably easier to reset the sensor’s history by un-exposing and re-exposing it. You might need to delete the old history from Eve, before new entries are shown.

Followed by a NodeJS error description

Which one?

brandungskieker commented 11 months ago

I run deCONZ on Version 2.23.00, I updated frequently via sudo apt-get update/upgrade. The uSD card works fine and has several GB free space.

Here is the full error log of an accessory. The error occurs just when I start the Eve app, without opening a specific accessory.

[21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (0/11): entry 66988 (index: 2476): {"time":1693815687,"o":0} (Mon Sep 04 2023 10:21:27) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (1/11): entry 66989 (index: 2477): {"time":1693816287,"o":0} (Mon Sep 04 2023 10:31:27) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (2/11): entry 66990 (index: 2478): {"time":1693816887,"o":0} (Mon Sep 04 2023 10:41:27) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (3/11): entry 66991 (index: 2479): {"time":1693817487,"o":0} (Mon Sep 04 2023 10:51:27) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (4/11): entry 66992 (index: 2480): {"time":1693817644,"o":0} (Mon Sep 04 2023 10:54:04) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (5/11): entry 66993 (index: 2481): {"time":1693818244,"o":0} (Mon Sep 04 2023 11:04:04) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (6/11): entry 66994 (index: 2482): {"time":1693818320,"o":0} (Mon Sep 04 2023 11:05:20) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries (7/11): entry 66995 (index: 2483): {"time":1550139262,"o":0} (Thu Feb 14 2019 11:14:22) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries: error: RangeError: The value of "value" is out of range. It must be >= 0 and <= 4294967295. Received -136638204 at new NodeError (node:internal/errors:405:5) at checkInt (node:internal/buffer:74:11) at writeU_Int32LE (node:internal/buffer:694:3) at Buffer.writeUInt32LE (node:internal/buffer:707:10) at History._onGetEntries (/var/lib/homebridge/node_modules/homebridge-deconz/node_modules/homebridge-lib/lib/ServiceDelegate/History.js:733:16) at CharacteristicDelegate._onGet (/var/lib/homebridge/node_modules/homebridge-deconz/node_modules/homebridge-lib/lib/CharacteristicDelegate.js:353:26) at Characteristic.emit (node:events:514:28) at /var/lib/homebridge/node_modules/homebridge/node_modules/hap-nodejs/src/lib/Characteristic.ts:2463:14 at new Promise (<anonymous>) at Characteristic.<anonymous> (/var/lib/homebridge/node_modules/homebridge/node_modules/hap-nodejs/src/lib/Characteristic.ts:2461:12) [21.9.2023, 21:47:10] [deCONZ] Stereoanlage History: History Entries: get: return "C6EFAQBFS2sAAQALogUBAJ1NawABAAujBQEA9U9rAAEAC6QFAQBNUmsAAQALpQUBAKVUawABAAumBQEA/VZrAAEAC6cFAQBVWWsAAQALqAUBAK1bawABAAupBQEABV5rAAEAC6oFAQBdYGsAAQALqwUBALViawABAA==" [21.9.2023, 21:47:11] [deCONZ] flush cachedAccessories

How do I un- and re-expose a sensors history?

ebaauw commented 11 months ago

By the looks of it, your system time was off while running Homebridge, causing Homebridge deCONZ to log a history entry for Thu Feb 14 2019 11:14:22. When sending the history to Eve, relative timestamps are used, from the start of keeping the history for the device, somewhere around Wed Jun 14 2023. Obviously, 2019 is way before 2023, resulting in an illegal negative relative timestamp.

Not sure I would be able to prevent the error: I could check the system time on startup against the time of the most recent history entry for each accessory to conclude something's wrong. However, there's no way of knowing whether the current system time is wrong (in the past), or whether the system time was wrong (in the future) when the last history entry was made. Also, it's really not a Homebridge nor Homebridge deCONZ (nor deCONZ) responsibility to keep an accurate system time.

Anyway, un-exposing and re-exposing the device would delete all history entries for the device, and restart the history keeping. See https://github.com/ebaauw/homebridge-deconz/wiki/Dynamic-Configuration on how to do that.

ebaauw commented 11 months ago

Check against time-travel in v1.0.1.