Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
11.96k stars 1.67k forks source link

LiXee ZLinky_TIC UnhandledPromiseRejectionWarning #11674

Closed roumano closed 2 years ago

roumano commented 2 years ago

What happened?

Got a issue with the Model :ZLinky_TIC, Vendor : LiXee ( https://www.zigbee2mqtt.io/devices/ZLinky_TIC.html ) i used the lasted OTA firmware : 4000-0005 My Linky is configured as standard mode (instead of default historique

I set this z2m configuration for this device :

    friendly_name: zlinky
    linky_mode: standard
    energy_phase: single_phase
    production: 'false'
    tarif: Historique - BASE
    kWh_precision: 2
    measurement_poll_interval: 60
    measurement_poll_chunk: 1

I regularly get this error (arround 3-5 minutes ) :

mars 02 10:11:54 rasp npm[27412]: zlinky config: standard, single_phase, false, BASE
mars 02 10:11:55 rasp npm[27412]: (node:27412) UnhandledPromiseRejectionWarning: Error: Read 0x00158d0005d28481/1 liXeePrivate(["currentTarif"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)
mars 02 10:11:55 rasp npm[27412]:     at DeconzAdapter.sendZclFrameToEndpoint (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/deconz/adapter/deconzAdapter.ts:649:23)
mars 02 10:11:55 rasp npm[27412]:     at Endpoint.sendRequest (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:20)
mars 02 10:11:55 rasp npm[27412]:     at Endpoint.read (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:472:28)
mars 02 10:11:55 rasp npm[27412]:     at Timeout._onTimeout (/data/zigbee2mqtt/node_modules/zigbee-herdsman-converters/devices/lixee.js:596:33)
mars 02 10:11:55 rasp npm[27412]: (node:27412) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 12)

But it's still able to retrieve data

What did you expect to happen?

to not crash

How to reproduce it (minimal and precise)

Zigbee2MQTT version

1.24.0 commit: 7a2ddf24

Adapter firmware version

0x26720700

Adapter

ConBee2

Debug log

No response

Koenkk commented 2 years ago

@vk496 could you check this?

vk496 commented 2 years ago

@roumano the error you show is originated in line 596, but it doesn't correspond to the current version of lixee.js (https://github.com/Koenkk/zigbee-herdsman-converters/blob/694c8e746d5a2bd3156cc3954010ebbea6fe0d30/devices/lixee.js#L596)

Please, could you check that you don't have enabled any external converter with old integration?

roumano commented 2 years ago

Hi @vk496 , For me, the master branch of zigbeemqtt is 1.24.0 In package.json ( https://github.com/Koenkk/zigbee2mqtt/blob/master/package.json ), the dependency is :

  "version": "1.24.0",
  "dependencies": {
    "zigbee-herdsman-converters": "14.0.438",
  }

The and file https://github.com/Koenkk/zigbee-herdsman-converters/blob/v14.0.438/devices/lixee.js is the same as me and different of https://github.com/Koenkk/zigbee-herdsman-converters/blob/694c8e746d5a2bd3156cc3954010ebbea6fe0d30/devices/lixee.js#L596)

vk496 commented 2 years ago

Hi,

Thnks for the info. Yes, you're right. For that version it match as expected: https://github.com/Koenkk/zigbee-herdsman-converters/blob/13f1160bb2a5406f7de5ae773d17eae03c371299/devices/lixee.js#L596

Even if you have this error, do you still able to see values from previous reads (NGTF)? Or is never able to read them?

roumano commented 2 years ago

I get this : NGTF (Supplier pricing schedule name) : BASE

vk496 commented 2 years ago

@Koenkk the device doesn't answer for read commands of some clusters, but it doesn't seem to be timeout. Do you think catch and ignore the read errors would be acceptable? I'm not sure if is possible to know why is not answering without very deep debugging, and most probably it will be related to the firmware/power of the device

Koenkk commented 2 years ago

@vk496

Do you think catch and ignore the read errors would be acceptable?

Sounds fine to me, you can use the logger to inform the users of any configure failures.

renaiku commented 2 years ago

@vk496 It might interest you

I found that in my z2m console (home assistant addon):

device firmware: 4000-0005
z2m HA addon version: 1.24.0-1

(meter_serial_number & site_id anonymized)

Zigbee2MQTT:info  2022-03-08 13:52:42: MQTT publish: topic 'zigbee2mqtt/Linky', payload '{"active_enerfy_out_d01":15507.875,"active_enerfy_out_d02":16708.4,"active_enerfy_out_d03":990.894,"active_enerfy_out_d04":1212.165,"active_power":792,"active_power_max":3340,"active_power_ph_b":1154,"apparent_power":1359,"available_power":9,"average_rms_voltage_meas_period":237,"current_date":"H220307192538","current_index_tarif":3,"current_price":"HEURES PLEINES","current_summ_delivered":34419.311,"current_tarif":"H SUPER CREUSES","current_tier10_summ_delivered":0,"current_tier1_summ_delivered":16115.256,"current_tier2_summ_delivered":15985.488,"current_tier3_summ_delivered":2318.567,"current_tier4_summ_delivered":0,"current_tier5_summ_delivered":0,"current_tier6_summ_delivered":0,"current_tier7_summ_delivered":0,"current_tier8_summ_delivered":0,"current_tier9_summ_delivered":0,"days_number_current_calendar":null,"days_number_next_calendar":null,"days_profile_current_calendar":null,"days_profile_next_calendar":null,"drawn_v_a_max_n1":4840,"linkquality":58,"message1":"PAS DE MESSAGE","message2":"","meter_serial_number":"XXXXXXXXXXXX","power_threshold":9,"relais":64,"rms_current":6,"rms_voltage":238,"site_id":"XXXXXXXXXXXX","software_revision":2,"start_mobile_point1":null,"start_mobile_point2":null,"start_mobile_point3":null,"status_register":"003A4801","stop_mobile_point1":null,"stop_mobile_point2":null,"stop_mobile_point3":null,"update":{"state":"idle"},"update_available":false}'
(node:386) UnhandledPromiseRejectionWarning: Error: Read 0x00158d0005d2a13c/1 liXeePrivate(["currentTarif","currentPrice","currentIndexTarif","currentDate","activeEnerfyOutD02","activeEnerfyOutD03","activeEnerfyOutD04","statusRegister"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Status 'INSUFFICIENT_SPACE')
    at Endpoint.checkStatus (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:317:28)
    at Endpoint.read (/app/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:480:22)
    at Timeout._onTimeout (/app/node_modules/zigbee-herdsman-converters/devices/lixee.js:596:33)
(node:386) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1106)

I was searching why the device was spamming the mqtt console with always the same payload, and why values (I was watching active_power) where only changing every 30minutes with this config:

image

EDIT: by default when 1st binding with the device, the measurement_poll_chunck was "0" (it's indicated "1" by default but it wasn't, I changed it myslef)

Pofilo commented 2 years ago

I can create (here or in the converters I don't know) an dedicated issue but it seems like measurement_poll_interval is not working well. I put it at 180 then 360 and I still get measures every 60-90 seconds. I'm not fluent with Javascript to debug this async part of the converter, have someone also notice this ?

renaiku commented 2 years ago

@Pofilo I came to this ticket because I had the same measures payload spamming the z2m console every few seconds even if I had 60 seconds in the measurement_poll_interval field. So your issue is also one of my issues. Please tag me if they ask you to open another ticket ;)

roumano commented 2 years ago

Hi @vk496 ,

I just switch to dev version to try and i get this error :

mars 14 18:10:58 rasp npm[29998]: zlinky config: standard, single_phase, false, BASE
mars 14 18:10:59 rasp npm[29998]: (node:29998) UnhandledPromiseRejectionWarning: Error: Read 0x00158d0005d28481/1 liXeePrivate(["currentTarif"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)
mars 14 18:10:59 rasp npm[29998]:     at DeconzAdapter.sendZclFrameToEndpoint (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/deconz/adapter/deconzAdapter.ts:649:23)
mars 14 18:10:59 rasp npm[29998]:     at Endpoint.sendRequest (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:299:20)
mars 14 18:10:59 rasp npm[29998]:     at Endpoint.read (/data/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:472:28)
mars 14 18:10:59 rasp npm[29998]:     at Timeout._onTimeout (/data/zigbee2mqtt/node_modules/zigbee-herdsman-converters/devices/lixee.js:623:33)
mars 14 18:10:59 rasp npm[29998]: (Use `node --trace-warnings ...` to show where the warning was created)
mars 14 18:10:59 rasp npm[29998]: (node:29998) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11)
mars 14 18:10:59 rasp npm[29998]: (node:29998) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

My version of zigbee2mqtt (build today) :

# jq '.version,.dependencies' package.json
"1.24.0-dev"
{
  "ajv": "^8.10.0",
  "bind-decorator": "^1.0.11",
  "connect-gzip-static": "^2.1.1",
  "core-js": "^3.21.1",
  "debounce": "^1.2.1",
  "deep-object-diff": "^1.1.7",
  "fast-deep-equal": "^3.1.3",
  "finalhandler": "^1.1.2",
  "git-last-commit": "^1.0.1",
  "humanize-duration": "^3.27.1",
  "js-yaml": "^4.1.0",
  "json-stable-stringify-without-jsonify": "^1.0.1",
  "mkdir-recursive": "^0.4.0",
  "moment": "^2.29.1",
  "mqtt": "4.3.6",
  "object-assign-deep": "^0.4.0",
  "rimraf": "^3.0.2",
  "semver": "^7.3.5",
  "source-map-support": "^0.5.21",
  "uri-js": "^4.4.1",
  "winston": "^3.6.0",
  "winston-syslog": "^2.5.0",
  "winston-transport": "^4.5.0",
  "ws": "^8.5.0",
  "zigbee-herdsman": "0.14.20",
  "zigbee-herdsman-converters": "14.0.450",
  "zigbee2mqtt-frontend": "0.6.79"
}
vk496 commented 2 years ago

@roumano thnks for the fast report. Since you can have this issue randomly on any reads, I just log them all and don't allow to break the execution. Now it should be fine, but take in account that if for some reason you are no longer able to read from the device, you will not notice it and will just have the old data (and logs about it, of course)

vk496 commented 2 years ago

@Koenkk having logger just on configure function may be a problem in the future, since console logs are not shown in the frontend AFAIK. But it seems that only me is using it, so I just let you know as information

renaiku commented 2 years ago

@roumano Have you got a not common electricity subscription ? I have "Heures Super Creuse" contract that add a third tarif ( not only hchp but hchphsp for me). So currentTarif value can be either 1 , 2 or 3 for me. Maybe it's the problem.

@vk496 maybe it's that.

vk496 commented 2 years ago

I don't think is related to the values that the device exposes, but the device. I would bet a power issue of the device itself. The Linky energy given to TIC devices is very very low and make the unstable during loads, like reads (thnks Enedis)

roumano commented 2 years ago

The read issue it's not only for currentTarif, i just apply the configuration from the #4000 and now can see the read error on several attributes :

mars 14 22:48:57 rasp npm[31760]: Failed to read zigbee attributes: Error: Read 0x00158d0005d28481/1 liXeePrivate(["currentTarif"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)

mars 14 22:50:05 rasp npm[31760]: Failed to read zigbee attributes: Error: Read 0x00158d0005d28481/1 haMeterIdentification(["availablePower"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)

mars 14 22:52:58 rasp npm[31760]: Failed to read zigbee attributes: Error: Read 0x00158d0005d28481/1 liXeePrivate(["startMobilePoint1"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)

mars 14 22:54:03 rasp npm[31760]: Failed to read zigbee attributes: Error: Read 0x00158d0005d28481/1 seMetering(["currentTier7SummDelivered"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)

PS : a physical change was make on my device (by the vendor) to make it more robust (before it's was disconnecting very often due to linky low energy power) PS2: i'm using the standard mode (instead of historique, usual mode) PS3: @renaiku , no it's the EDF, Tarif Bleu, option base, very basic PS4: @vk496 , it's totally fine if it's not able to read a attribut sometimes...

Tolriq commented 2 years ago

@roumano how did you get that hardware change done? Who did you contact?

roumano commented 2 years ago

@Tolriq : https://github.com/fairecasoimeme/Zlinky_TIC#errata-hardware

Tolriq commented 2 years ago

Thanks mine have it :( Will contact them and see then.