Timeout error during pairing catching with a nice error message?

[louismulder]

I see a timeout error during pairing with a program trace dump. The device is working correct after pairing but the error gives not a fine feeling. Maybe it is possible to catch this error in a nice message?

See the log: info 2020-01-20 13:05:18: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99}' error 2020-01-20 13:05:18: No converter available for 'state' () info 2020-01-20 13:05:20: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13011}' info 2020-01-20 13:05:26: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13223}' error 2020-01-20 13:05:28: Failed to configure '0x04cf8cdf3c772da3', attempt 1 (Error: Timeout - 0 - 1 - 11 - 1 - 7 after 10000ms at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) at ontimeout (timers.js:436:11) at tryOnTimeout (timers.js:300:5) at listOnTimeout (timers.js:263:5) at Timer.processTimers (timers.js:223:10)) info 2020-01-20 13:05:30: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13011}' info 2020-01-20 13:05:30: Configuring '0x04cf8cdf3c772da3' info 2020-01-20 13:05:34: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13223}' info 2020-01-20 13:05:38: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13011}' error 2020-01-20 13:05:42: Failed to configure '0x04cf8cdf3c772da3', attempt 2 (Error: Timeout - 0 - 1 - 12 - 1 - 7 after 10000ms at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) at ontimeout (timers.js:436:11) at tryOnTimeout (timers.js:300:5) at listOnTimeout (timers.js:263:5) at Timer.processTimers (timers.js:223:10)) info 2020-01-20 13:05:44: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13223}' info 2020-01-20 13:05:44: Configuring '0x04cf8cdf3c772da3' info 2020-01-20 13:05:49: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13011}' info 2020-01-20 13:05:52: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":99,"illuminance":13223}' error 2020-01-20 13:05:56: Failed to configure '0x04cf8cdf3c772da3', attempt 3 (Error: Timeout - 0 - 1 - 13 - 1 - 7 after 10000ms at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) at ontimeout (timers.js:436:11) at tryOnTimeout (timers.js:300:5) at listOnTimeout (timers.js:263:5) at Timer.processTimers (timers.js:223:10)) info 2020-01-20 13:05:58: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":94,"illuminance":11462}' info 2020-01-20 13:06:01: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":86,"illuminance":12553}' info 2020-01-20 13:06:04: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":84,"illuminance":12042}' info 2020-01-20 13:06:12: MQTT publish: topic 'zigbee2mqtt/0x04cf8cdf3c772da3', payload '{"battery":"100.00","voltage":3100,"linkquality":76,"illuminance":11761}'

[Koenkk]

What device is this?

[louismulder]

What device is this?

Sorry Koen. Forgot to tellen GZCGQ01LM-lumi.sen_ill.mgl01 I thought it was a common issue. To be honest the distance from the device to the coordinator was about 2 meter during pairing

[Koenkk]

Can you provide the herdsman debug logging when pairing this device?

To enable herdsman debug logging, see https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging

[louismulder]

@Koenkk I have created a log as requested. This one is created in the Windows environment. I have tested with a CC2531 as coordinator with zstack version 3.0 and 1.2 both give the same result. Also tested in the Linux environment with the same result.

issue2786.log

[Koenkk]

This is only a small part of the log, please provide the log from starting zigbee2mqtt, pairing the device upon seeing interview failed

[louismulder]

@Koenkk I have created a new log as requested. issue2786_2.log

[Koenkk]

Can you keep pressing the button on the device to keep it awake when pairing?

[louismulder]

Can you keep pressing the button on the device to keep it awake when pairing?

@Koenkk This solution gives the same error

[Koenkk]

Today I received the device and could reproduce the issue, fixed in the latest dev branch. Thanks!

[thehijacker]

Is this already in 1.10? Just updated to 1.10 and I still get this on start:

error 2020-02-07 10:34:16: Failed to configure 'Light Sensor Aquarium', attempt 2 (Error: Bind 0x04cf8cdf3c7754a2/1 genPowerCfg from '0x00124b001f3205ec/1' failed (Err
or: AREQ - ZDO - bindRsp after 10000ms)
    at Endpoint.<anonymous> (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/controller/model/endpoint.js:235:23)
    at Generator.throw (<anonymous>)
    at rejected (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/controller/model/endpoint.js:6:65))