Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PM Failed to ping in logs #1248

Closed
tweaker opened this issue Mar 13, 2019 · 25 comments
Closed

PM Failed to ping in logs #1248

tweaker opened this issue Mar 13, 2019 · 25 comments
Milestone

Comments

@tweaker
Copy link

tweaker commented Mar 13, 2019

After upgrading to 1.2.1 in the logs appeared information that the outlet is not available.
Before that, there was version 1.1.1, but it was not there.
Although the outlet is operated from the Home Assistant

  zigbee2mqtt:error 3/13/2019, 7:13:08 PM Failed to ping 0x00158d00022daf0a
  zigbee2mqtt:info 3/13/2019, 7:13:14 PM Zigbee publish to device '0x00158d00022daf0a', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:info 3/13/2019, 7:13:14 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"ON","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:info 3/13/2019, 7:13:14 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"ON","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:info 3/13/2019, 7:13:14 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"ON","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:info 3/13/2019, 7:13:15 PM Zigbee publish to device '0x00158d00022daf0a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:info 3/13/2019, 7:13:15 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"OFF","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:info 3/13/2019, 7:13:15 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"OFF","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:info 3/13/2019, 7:13:15 PM MQTT publish: topic 'zigbee2mqtt/living_room_switch_orico_hdd_hub', payload '{"state":"OFF","power":0,"voltage":224.4,"consumption":6.88,"temperature":38,"linkquality":141}'
  zigbee2mqtt:error 3/13/2019, 7:14:07 PM Failed to ping 0x00158d00022daf0a
  zigbee2mqtt:error 3/13/2019, 7:15:07 PM Failed to ping 0x00158d00022daf0a
  zigbee2mqtt:error 3/13/2019, 7:16:08 PM Failed to ping 0x00158d00022daf0a

UPD:
I rolled back to version 1.1.1, this error does not appear.

@tunip
Copy link

tunip commented Mar 13, 2019

I also have these kind of messages in the log.

 zigbee2mqtt:error 3/13/2019, 9:44:02 PM Failed to ping 0x00124b001bc74797
  zigbee2mqtt:error 3/13/2019, 9:44:02 PM Failed to ping 0x00124b001bc74b3d
  zigbee2mqtt:error 3/13/2019, 9:45:03 PM Zigbee publish to device '0x0017880100c3dfdb', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 183. APS no ack.
  zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc749ee
  zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc742f8
  zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc74797
  zigbee2mqtt:error 3/13/2019, 9:45:29 PM Failed to ping 0x00124b001bc74b3d
  zigbee2mqtt:error 3/13/2019, 9:45:33 PM Zigbee publish to device '0x0017880100c3dfdb', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: Timed out after 30000 ms
/app/node_modules/cc-znp/lib/ccznp.js:176
        throw new Error('ccznp has not been initialized yet');
        ^

Error: ccznp has not been initialized yet
    at CcZnp.request (/app/node_modules/cc-znp/lib/ccznp.js:176:15)
    at Controller.request (/app/node_modules/zigbee-shepherd/lib/components/controller.js:322:13)
    at Object.af.send (/app/node_modules/zigbee-shepherd/lib/components/af.js:106:16)
    at Object.af.zclFunctional (/app/node_modules/zigbee-shepherd/lib/components/af.js:384:12)
    at ZShepherd._functional (/app/node_modules/zigbee-shepherd/lib/shepherd.js:718:20)
    at Endpoint.ep.functional (/app/node_modules/zigbee-shepherd/lib/shepherd.js:586:25)
    at Object.queue.push [as func] (/app/lib/zigbee.js:265:24)
    at ZigbeeQueue.executeNext (/app/lib/util/zigbeeQueue.js:63:18)
    at Timeout.timer.setInterval [as _onTimeout] (/app/lib/util/zigbeeQueue.js:33:18)
    at ontimeout (timers.js:436:11)
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! [email protected] start: `node index.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the [email protected] start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /var/lib/zigbee2mqtt/.npm/_logs/2019-03-13T20_45_34_028Z-debug.log
  zigbee2mqtt:error 3/13/2019, 9:46:50 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:00 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:04 PM Zigbee publish to device '0x0017880102ca91df', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:21 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:24 PM Zigbee publish to device '0x0017880102ca91df', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:31 PM Zigbee publish to device '0x0017880102ca91df', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:34 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:47:50 PM Failed to ping 0x00124b001bc749ee
  zigbee2mqtt:error 3/13/2019, 9:47:51 PM Failed to ping 0x00124b001bc742f8
  zigbee2mqtt:error 3/13/2019, 9:47:51 PM Failed to ping 0x00124b001bc74797
  zigbee2mqtt:error 3/13/2019, 9:47:51 PM Failed to ping 0x00124b001bc74b3d
  zigbee2mqtt:error 3/13/2019, 9:48:56 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:48:59 PM Zigbee publish to device '0x0017880102ca91df', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:49:05 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:49:19 PM Zigbee publish to device '0x0017880102ca91df', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:49:24 PM Zigbee publish to device '0x001788010216e02a', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:49:26 PM Zigbee publish to device '0x0017880100c3dfdb', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.
  zigbee2mqtt:error 3/13/2019, 9:49:59 PM Failed to ping 0x00124b001bc742f8
  zigbee2mqtt:error 3/13/2019, 10:13:00 PM Failed to ping 0x00124b001bc74797
  zigbee2mqtt:error 3/13/2019, 10:44:59 PM Failed to ping 0x00124b001bc749ee

@MikeVRT
Copy link

MikeVRT commented Mar 14, 2019

Just updated to 1.2.1 + 20190223. Got same error for my 0x.. of my router (based on CC2531 stick as coordinator too).

...
2019-3-14 20:41:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:42:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:43:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:44:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:45:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:46:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:47:58 - error: Failed to ping 0x00185e4418ed2d9e
2019-3-14 20:48:58 - error: Failed to ping 0x00185e4418ed2d9e
...

Before it worked good but with one nuance - router's link quality always was "0" in logs.

More over - paired devices not disappeared after reflash coordinator to 20190223 as promised. But their data flow not changes now (door open/close for example). It's problem for all devices - connected to coordinator directly or through router. Unfortunately I see "repairing again" on horizon :(

@Koenkk
Copy link
Owner

Koenkk commented Mar 15, 2019

Zigbee2mqtt 1.2.1 isn't the issue probably, the difference is that 1.1.1 logged it as debug while 1.2.1 logs it as error. Can you confirm when settings log_level: debug for zigbee2mqtt 1.1.1 you see the same issue? (http://www.zigbee2mqtt.io/configuration/configuration.html)

@tweaker
Copy link
Author

tweaker commented Mar 15, 2019

Zigbee2mqtt 1.2.1 isn't the issue probably, the difference is that 1.1.1 logged it as debug while 1.2.1 logs it as error. Can you confirm when settings log_level: debug for zigbee2mqtt 1.1.1 you see the same issue? (http://www.zigbee2mqtt.io/configuration/configuration.html)

The error is present, with log_level: debug and log_level: error.

@Koenkk
Copy link
Owner

Koenkk commented Mar 15, 2019

@tweaker also in zigbee2mqtt 1.1.1?

@tweaker
Copy link
Author

tweaker commented Mar 15, 2019

@tweaker also in zigbee2mqtt 1.1.1?

Yes, the same message is available in 1.1.1.
What can this mean? Faulty device (ZNCZ02LM)?

2019-3-15 13:27:52 - debug: Check online living_room_switch_orico_hdd_hub 0x00158d00022daf0a 
2019-3-15 13:28:02 - debug: Failed to ping 0x00158d00022daf0a 

@tunip
Copy link

tunip commented Mar 15, 2019

In my case with Zigbee2mqtt 1.2.1, if i only see "Failed to ping" messages, devices are not operating.
Have then to replug CC2531 usb-stick and restart zigbee2mqtt. Will test later more with debug logging enaled.

@Koenkk Koenkk added this to the 1.3 milestone Mar 15, 2019
@MikeVRT
Copy link

MikeVRT commented Mar 15, 2019

In my case:

  1. all devices that connected directly to coordinator (CC2531, 20190223) starts work after 8-12 hours (devices that I pressed button yesterday - immediately).
  2. all devices that connected through router (CC2531, CC2531_router_2018_09.zip) still not works in reality, BUT always listed as joined and published in mqtt in log on each zigbee2mqtt restart. All with linkquality 0. (I tried to repower router of course). "Failed to ping..." for router still here.

Maybe we have new firmware for CC2531 router, based on new coordinator's 20190223 fw and it's MUST be updated?
Or maybe preview workable router & end devices with linkquality=0 now cut by new software logic?

But as I can see, problem not in real linkquality and distance:

The controller can't ping the routers (mainly QBKG11LM), even if the distant is less then 1m, and the link quality > 120 which published into mqtt

@Fabiancrg
Copy link

I have this message also sometimes on Aqara LED bulb but On/Off command are still working.
After a complete power off / power on, message disappeared for a while

@tweaker
Copy link
Author

tweaker commented Mar 17, 2019

I de-energized the outlet and turned it on again. In the logs:

2019-3-17 16:59:32 - debug: Check online living_room_switch_orico_hdd_hub 0x00158d00022daf0a 
2019-3-17 16:59:32 - debug: Successfully pinged 0x00158d00022daf0a 
2019-3-17 17:00:32 - debug: Check online living_room_switch_orico_hdd_hub 0x00158d00022daf0a 
2019-3-17 17:00:32 - debug: Successfully pinged 0x00158d00022daf0a 
2019-3-17 17:01:32 - debug: Check online living_room_switch_orico_hdd_hub 0x00158d00022daf0a 
2019-3-17 17:01:32 - debug: Successfully pinged 0x00158d00022daf0a 

@tunip
Copy link

tunip commented Mar 19, 2019

De-energizing did not help. After a few days the message comes back and the router is not operating if the message occurs.

In my network the four IDs which showing "Failed to ping" are only my CC2530 + CC2591 routers:

zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc749ee
zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc742f8
zigbee2mqtt:error 3/13/2019, 9:45:28 PM Failed to ping 0x00124b001bc74797
zigbee2mqtt:error 3/13/2019, 9:45:29 PM Failed to ping 0x00124b001bc74b3d

info: router_erdgeschoss    (0x00124b001bc749ee): CC2530.ROUTER
info: router_obergeschoss   (0x00124b001bc742f8): CC2530.ROUTER
info: router_dachgeschoss   (0x00124b001bc74797): CC2530.ROUTER
info: router_kellergeschoss (0x00124b001bc74b3d): CC2530.ROUTER

De-energized this router last sunday:

zigbee2mqtt:info 3/19/2019, 9:22:32 AM MQTT publish: topic 'zigbee2mqtt/router_dachgeschoss', payload '{"state":true,"linkquality":65}'
zigbee2mqtt:error 3/19/2019, 9:23:12 AM Failed to ping 0x00124b001bc74797
zigbee2mqtt:info 3/19/2019, 9:23:32 AM MQTT publish: topic 'zigbee2mqtt/router_dachgeschoss', payload '{"state":true,"linkquality":68}'

I re-pair all four routers the next days and see what happens.

@MikeVRT
Copy link

MikeVRT commented Mar 19, 2019

De-energizing did not help.

Me too. Still waiting fix. All sensors bounded to router doesn't work more few days.

I re-pair all four routers the next days and see what happens.

For re-pair router, you must reflash it - are you reflashed four routers??? :(

@tunip
Copy link

tunip commented Mar 19, 2019

@MikeVRT thx, i know that i have to reflash all the routers. Yes i will do this the next days...

Koenkk added a commit that referenced this issue Mar 23, 2019

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
@Koenkk
Copy link
Owner

Koenkk commented Mar 23, 2019

Is this issue still present in the latest dev branch?

@tunip
Copy link

tunip commented Mar 23, 2019

Installed the the dev branch now. In a few hours i will give you a feedback.

@dh-harald
Copy link

dh-harald commented Mar 23, 2019

I've installed the dev branch (from docker) and I had a small glitch, I don't know why, but it looks much much better then before the fix:

  zigbee2mqtt:debug 3/23/2019, 10:25:48 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":1}}' of device 'lumi.ctrl_ln1.aq1' (0x00158d0002c5ca05)
  zigbee2mqtt:debug 3/23/2019, 10:25:48 PM Successfully pinged 0x00158d0002c5ca05
  zigbee2mqtt:error 3/23/2019, 10:25:59 PM Failed to ping 0x00158d0002c5ca05
  zigbee2mqtt:info 3/23/2019, 10:25:59 PM MQTT publish: topic 'zigbee2mqtt/light_kids/availability', payload 'offline'

Anyway, the devices looks online (except this rouge switch)
Big thanks!
ps: got it... It looks, it's pinging the xiaomi devices with basic (its working) and default method (not working) as well, so the default method put the device offline state
ps2: If I add availability_timeout: 0, it's pinging only the xiaomi devices with basic method without any issues, but the default method for any devices (xiaomi and non-xiaomi) stopped, no other ping... I don't know is it the excepted behaviour

@Koenkk
Copy link
Owner

Koenkk commented Mar 24, 2019

Xiaomi routers are always pinged (to keep them awake). So that's why you will still see pinging of these device with device availability disabled.

Device availability will now also use the basic ping mechanism. So your issues should be solved with the latest dev, can you confirm?

@dh-harald
Copy link

I think, you should use the basic method for checking availability for xiaomi devices, because the basic is still not working (even if the devices are awake). With default method makes devices offline.

@Koenkk
Copy link
Owner

Koenkk commented Mar 24, 2019

@dh-harald that's what I've just implemented. (basic will be used for Xiaomi, default for others)

@tunip
Copy link

tunip commented Mar 24, 2019

Looks good right now. Many thx for the fix.

@dh-harald
Copy link

dh-harald commented Mar 24, 2019

@Koenkk It looks perfect... I'm running it for an hour without any problem... I think, it's solved our xiaomi related problem. Thanks for it!

@Koenkk
Copy link
Owner

Koenkk commented Mar 24, 2019

great, thanks all!

@Koenkk Koenkk closed this as completed Mar 24, 2019
@MikeVRT
Copy link

MikeVRT commented Mar 25, 2019

I will check too!

@cvladan
Copy link

cvladan commented Mar 25, 2019

As Hass.io user, what should I install to make this work? Still getting lots of error: Failed to ping messages. Should I install zigbee2mqtt-edge as it is development build of the zigbee2mqtt add-on?

I tried it, but have seen no difference.

@MikeVRT
Copy link

MikeVRT commented Apr 15, 2019

Is it fixed in stable 1.3.0?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants