Page 1 of 1

Pizigate very slow reaction on zigbee devices and restarts

Posted: Thursday 12 May 2022 22:48
by lostodos
Hi,

I have noticed that when switching zigbee devices (that are connected with my Pizigate) on and off through Domoticz that there is a delay in these devices responding and sometimes they are not responding at all. In these cases the zigate module seems to reboot. I have added some logs from Domoticz below.

Domoticz version: 2022.1 (build 14318)
Zigate plugin: 6.1.004
Firmware Zigate: 0321


Can someone maybe help me to figure out what is going wrong?....

Thnx!

Kind regards,

Mark Reijnders

-----
Domoticz status log:

2022-05-12 22:45:29.113 Status: Zigate: Plugin Restart command : http://127.0.0.1:8080/json.htm?type=com ... loglevel=7
2022-05-12 22:45:29.156 Status: Zigate: Stop directive received.
2022-05-12 22:45:29.190 Status: Zigate: ZigateTransport: ZiGateSerialListen Thread stop.
2022-05-12 22:45:29.190 Status: Zigate: ZigateTransport: thread_processing_and_sending Thread stop.
2022-05-12 22:45:30.284 Status: Zigate: ZigateTransport: writer_thread Thread stop.
2022-05-12 22:45:30.295 Status: Zigate: Statistics on message
2022-05-12 22:45:30.295 Status: Zigate: PDM load(s) : 0
2022-05-12 22:45:30.295 Status: Zigate: ZiGate reacting time
2022-05-12 22:45:30.295 Status: Zigate: Max : 0 sec
2022-05-12 22:45:30.295 Status: Zigate: Average : 0 sec
2022-05-12 22:45:30.295 Status: Zigate: ZiGate processing time on Rx
2022-05-12 22:45:30.295 Status: Zigate: Max : 0 sec
2022-05-12 22:45:30.295 Status: Zigate: Average : 0 sec
2022-05-12 22:45:30.295 Status: Zigate: Sent:
2022-05-12 22:45:30.295 Status: Zigate: TX commands : 65
2022-05-12 22:45:30.295 Status: Zigate: Max Load (Queue) : 11
2022-05-12 22:45:30.295 Status: Zigate: Max aPDU (Queue) : 2
2022-05-12 22:45:30.295 Status: Zigate: Max nPDU (Queue) : 1
2022-05-12 22:45:30.295 Status: Zigate: TX failed : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: TX timeout : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: TX data timeout : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: TX reTransmit : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: TX APS Failure : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: TX APS Ack : 40 (61.54%)
2022-05-12 22:45:30.295 Status: Zigate: TX APS Nck : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: Received:
2022-05-12 22:45:30.295 Status: Zigate: RX frame : 170
2022-05-12 22:45:30.295 Status: Zigate: RX crc errors : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: RX lentgh errors : 0 (0.0%)
2022-05-12 22:45:30.295 Status: Zigate: RX clusters : 45
2022-05-12 22:45:30.295 Status: Zigate: RX clusters KO : 0
2022-05-12 22:45:30.295 Status: Zigate: Operating time : 0 Hours 14 Mins 41 Secs
2022-05-12 22:45:30.507 Status: Zigate: Exiting work loop.
2022-05-12 22:45:30.561 Status: Zigate: Stopping threads.
2022-05-12 22:45:30.561 Status: Zigate: Stopped.
2022-05-12 22:45:30.561 Status: Zigate: Started.
2022-05-12 22:45:30.561 Status: Incoming connection from: 127.0.0.1
2022-05-12 22:45:30.561 Status: Zigate: Entering work loop.
2022-05-12 22:45:31.397 Status: Zigate: Initialized version 6.2, author 'pipiche38'
2022-05-12 22:45:31.410 Status: Zigate: enablegroupmanagement set to 1
2022-05-12 22:45:31.410 Status: Zigate: PluginAnalytics set to 1
2022-05-12 22:45:31.410 Status: Zigate: zigatePartOfGroup0000 set to 1
2022-05-12 22:45:31.411 Status: Zigate: reenforceConfigureReporting set to 1
2022-05-12 22:45:31.411 Status: Zigate: channel set to 20
2022-05-12 22:45:31.411 Status: Zigate: filename set to /home/pi/domoticz/plugins/Domoticz-Zigate/Conf/PluginConf-06.json
2022-05-12 22:45:31.411 Status: Zigate: pluginHome set to /home/pi/domoticz/plugins/Domoticz-Zigate/
2022-05-12 22:45:31.411 Status: Zigate: homedirectory set to /home/pi/domoticz/plugins/Domoticz-Zigate/
2022-05-12 22:45:31.411 Status: Zigate: pluginData set to /home/pi/domoticz/plugins/Domoticz-Zigate/Data/
2022-05-12 22:45:31.411 Status: Zigate: pluginConfig set to /home/pi/domoticz/plugins/Domoticz-Zigate/Conf/
2022-05-12 22:45:31.411 Status: Zigate: pluginOTAFirmware set to /home/pi/domoticz/plugins/Domoticz-Zigate/OTAFirmware/
2022-05-12 22:45:31.411 Status: Zigate: pluginReports set to /home/pi/domoticz/plugins/Domoticz-Zigate/Reports/
2022-05-12 22:45:31.411 Status: Zigate: pluginWWW set to /home/pi/domoticz/plugins/Domoticz-Zigate/www/
2022-05-12 22:45:31.411 Status: Zigate: pluginLogs set to /home/pi/domoticz/plugins/Domoticz-Zigate/Logs/
2022-05-12 22:45:31.411 Status: Zigate: debugMatchId set to 2a38
2022-05-12 22:45:31.411 Status: Zigate: logDeviceUpdate set to 0
2022-05-12 22:45:31.411 Status: Zigate: debugInput set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugBasicOutput set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugWriteAttributes set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugReadAttributes set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugCluster set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugWidget set to 1
2022-05-12 22:45:31.411 Status: Zigate: debugTuya set to 1
2022-05-12 22:45:31.415 Status: Zigate: Please watch plugin log into /home/pi/domoticz/plugins/Domoticz-Zigate/Logs//PluginZigbee_06.log
2022-05-12 22:45:31.419 Status: Zigate: Zigate plugin stable6-6.1.004 started
2022-05-12 22:45:31.442 Status: Zigate: DeviceConf loaded - 23 confs loaded
2022-05-12 22:45:31.613 Status: Zigate: DeviceConf loaded - 334 confs loaded
2022-05-12 22:45:31.614 Status: Zigate: load ListOfDevice
2022-05-12 22:45:31.758 Status: Zigate: 21 Entries loaded from /home/pi/domoticz/plugins/Domoticz-Zigate/Data/DeviceList-6.txt
2022-05-12 22:45:31.765 Status: Zigate: Transport mode: PI
2022-05-12 22:45:31.807 Status: Zigate: Python version: ['3.7.3 (default, Jul 25 2020, 13:03:44) ', '[GCC 8.3.0]'] dist: ('debian', '10.8', '') linux_distribution: ('debian', '10.8', '') system: Linux machine: armv7l platform: Linux-5.10.63-v7l+-armv7l-with-debian-10.8 uname: uname_result(system='Linux', node='domoticz', release='5.10.63-v7l+', version='#1459 SMP Wed Oct 6 16:41:57 BST 2021', machine='armv7l', processor='') version: #1459 SMP Wed Oct 6 16:41:57 BST 2021 mac_ver: ('', ('', '', ''), '')
2022-05-12 22:45:32.516 Status: Zigate: ZigateTransport: Serial Connection open: Serial<id=0xae992310, open=True>(port='/dev/serial0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=None, xonxoff=False, rtscts=False, dsrdtr=False)
2022-05-12 22:45:32.517 Status: Zigate: ZigateTransport: writer_thread Thread start.
2022-05-12 22:45:32.520 Status: Zigate: ZigateTransport: thread_processing_and_sending Thread start.
2022-05-12 22:45:32.523 Status: Zigate: Start Web Server connection
2022-05-12 22:45:32.530 Status: Zigate: Web backend for Web User Interface started on port: 9440
2022-05-12 22:45:41.173 Status: Zigate: ==> Transport Mode switch to full mode
2022-05-12 22:45:41.177 Status: Zigate: ZiGate Classic PDM (legacy)
2022-05-12 22:45:41.178 Status: Zigate: Installer Version Number: 0321
2022-05-12 22:45:41.178 Status: Zigate: Branch Version: ==> Production <==
2022-05-12 22:45:51.162 Status: Zigate: Zigbee Coordinator ieee: 00158d0003af5c82 , short addr: 0000
2022-05-12 22:45:51.162 Status: Zigate: Network state UP, PANID: fd33 extPANID: 0x1978e83c71d7f644 Channel: 20
2022-05-12 22:45:56.094 Status: Zigate: Request Disabling Accepting new Hardware
2022-05-12 22:46:01.073 Status: Zigate: Zigate set to Certification : 1/CE -> CE
2022-05-12 22:46:01.075 Status: Zigate: Start Group Management
2022-05-12 22:46:01.082 Status: Zigate: Plugin with Zigate, firmware 0321 correctly initialized
2022-05-12 22:46:04.653 Status: Zigate: Accepting new Hardware: Disable (Off)
2022-05-12 22:46:04.790 Status: Zigate: Number of devices recently active in Zigate = 9
2022-05-12 22:46:04.791 Status: Zigate: [00] DevID: 00 Network addr: bc6c IEEE: 842e14fffe8c68b0 LQI: 224 power: 00 Model: TRADFRI onoff switch ( switch-tv )
2022-05-12 22:46:04.792 Status: Zigate: [01] DevID: 28 Network addr: 6cb3 IEEE: b4e3f9fffea3f9b9 LQI: 111 power: 01 Model: TRADFRI control outlet ( stopcontact-badkamer )
2022-05-12 22:46:04.792 Status: Zigate: [02] DevID: 29 Network addr: 24a6 IEEE: bc33acfffe5f5fc2 LQI: 086 power: 01 Model: TRADFRI control outlet ( Outlet02 )
2022-05-12 22:46:04.793 Status: Zigate: [03] DevID: 2a Network addr: 5cc2 IEEE: 842e14fffe4353d8 LQI: 122 power: 01 Model: TRADFRI bulb E27 WW 806lm ( Lamp-Kamer-TV-806lm )
2022-05-12 22:46:04.794 Status: Zigate: [04] DevID: 2b Network addr: eb03 IEEE: 0c4314fffefda827 LQI: 066 power: 01 Model: TRADFRI bulb GU10 WW 400lm ( Lamp-achter-03 )
2022-05-12 22:46:04.794 Status: Zigate: [05] DevID: 2c Network addr: d496 IEEE: 50325ffffe261fab LQI: 087 power: 01 Model: TRADFRI bulb GU10 WW 400lm ( Lamp-achter-02 )
2022-05-12 22:46:04.795 Status: Zigate: [06] DevID: 2d Network addr: 9dfb IEEE: 842e14fffea71b7c LQI: 093 power: 01 Model: TRADFRI bulb E27 WW 806lm ( Lamp-Kamer-Eettafel-806lm )
2022-05-12 22:46:04.796 Status: Zigate: [07] DevID: 2e Network addr: 8d11 IEEE: 842e14fffe5af61b LQI: 093 power: 01 Model: TRADFRI control outlet ( Outlet01 )
2022-05-12 22:46:04.796 Status: Zigate: [08] DevID: 2f Network addr: d9b4 IEEE: bc33acfffe5f6318 LQI: 111 power: 01 Model: TRADFRI control outlet ( Stopkontact-Vloer )


Domoticz error log:

2022-05-12 20:24:31.096 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 21:19:08.127 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 21:23:15.128 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 21:25:09.275 Error: Zigate: check_frame_lenght
2022-05-12 21:25:09.278 Error: Zigate: on_message Frame error Crc/len bytearray(b"\x01\x81\xa8!\n\'\ngJ!\n\xa4\xa7\xa4\xa4$\n\xa4\xa4d\x0e \xa5\xa4%\x85\n\xa4\x88\x02\x8d\x11\xb6\x00\x01\x00\x03")
2022-05-12 21:35:12.125 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 21:48:19.119 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 22:10:46.101 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 22:20:03.086 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 22:24:00.091 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 22:30:47.105 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect
2022-05-12 22:45:29.109 Error: Zigate: pingZigate - no Heartbeat with Zigate, try to reConnect

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 8:24
by pipiche
Quiet hard to diagnose , but for sure there is a communication issue between the plugin and the UART of the PiZigate.

Did you change anything recently ?

Do you have any other error messages in the system log ( dmesg ) ? Like power issues ?

Via the WebUI Tools>Debug menu can you enable "NXPExtendedErrorCode" this will help to see if there is any internal error on the Zigate itself.

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 16:19
by lostodos
Hi Pipiche,

Thank you for the reply!

Nothing changed in my setup last weeks, i have updated the plugin to v6.1.004 yesterday hoping to resolve the issue but it didn't unfortunately. Since this morning the issue has not occurred yet but i enabled the debug setting that you mentioned and will come back here with results.

Thanks!

Kind regards,

Mark

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 16:21
by pipiche
How old is your PiZigate ?

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 18:04
by lostodos
I purchased it in october 2020 so basically little over 1,5 years old i would think.

Could it be a problem with older hardware (or malfunctioning hardware)?

Thanks.

Kind regards,

Mark

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 19:55
by pipiche
I see much more an hardware issue rather than something else. Except if there is some firmware error, like the PiZigate do not communicate anymore.
Some issues could be related to your power adapter failing, and which can impact also the SDcard.
Let see how it evolves with the log

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 20:01
by lostodos
Thanks Pipiche. I will monitor the logs closely next few days.

I did notice the temperature being little over 80 degrees on the Raspberry, not sure if that can cause these issues but ordered a fan neverteless to get the temperature down as well.

Kind regards,

Mark

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Friday 13 May 2022 22:53
by pipiche
80° temperature that looks terrible, no ?

To prevent overheating, all Raspberry Pi boards begin to throttle the processor when the temperature reaches 80°C and even further when it reaches the max temp of 85°C.
https://raspberrypi.stackexchange.com/q ... exposed-to


You are probably on a right track with the FAN ;-)

Re: Pizigate very slow reaction on zigbee devices and restarts

Posted: Monday 16 May 2022 12:23
by lostodos
Hi Pipiche,

Just a quick update. I installed the fan two days ago and did not have the issues since. Temperature is and stays around 58/59 degrees now instead of 80/81 degrees before.

So i guess it was the temperature!

Thanks again for your help!

Kind regards,

Mark