Lots of error messages in run-app.log files

wlarmon · October 16, 2019, 11:16am

First post. I’ve been using Webthings Gateway for almost two months but today is the first time I registered so I could post.

Everything mostly works but sometimes the gateway doesn’t respond (to inputs like on/off switches) for upwards of a minute. I started tailing the most recent ~/.mozilla-iot/log/run-app.log. Before attempting to explain a complete interaction interspersed with yards of logs, I’ll just show a few snippits of error messages.

2019-10-15 16:56:08.528 INFO   : getValue for property on for: X10 On/Off Switch (A10) returning false
2019-10-15 16:56:08.954 ERROR  : Error setting value for thingId: etekcity-8d42f4a6-f8f3-4600-9f7d-03b9b30955f9 property: on value: false
2019-10-15 16:56:08.967 WARN   : Rule set failed, retrying once { code: 500,
  message: 'setProperty: device: etekcity-8d42f4a6-f8f3-4600-9f7d-03b9b30955f9 not found.' }
2019-10-15 16:56:08.970 ERROR  : Error setting value for thingId: etekcity-8d42f4a6-f8f3-4600-9f7d-03b9b30955f9 property: on value: false
2019-10-15 16:56:08.974 WARN   : Rule set failed completely { code: 500,
  message: 'setProperty: device: etekcity-8d42f4a6-f8f3-4600-9f7d-03b9b30955f9 not found.' }
2019-10-15 16:56:08.997 INFO   : getValue for property on for: X10 On/Off Switch (A9) returning false
2019-10-15 16:56:09.028 WARN   : Unable to dispatch action requestAction: device: Night light state not found.

[snip]

2019-10-15 18:22:38.978 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000105c4fb 8c2b
2019-10-15 18:26:10.154 INFO   : zigbee: Kicking WatchDog for 3600 seconds
2019-10-15 18:31:57.361 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000105c4fb 8c2b
2019-10-15 18:31:57.366 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000105c4fb 8c2b

[snip]

2019-10-15 18:32:47.513 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000105c4fb 8c2b
2019-10-15 18:32:54.347 ERROR  : etekcity: 2019-10-15 18:32:54,344 - ERROR - HTTPSConnectionPool(host='smartapi.vesync.com', port=443): Read timed out. (read timeout=5)
2019-10-15 18:42:05.876 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000105c4fb 8c2

I’m not sure how much log detail to post. I’ve got a lot of Zigbee ROUTE_DISCOVERY_FAILED errors.

I have a mixture of X-10 (CM11A interface, lamp and appliance modules), Zigbee (ConBee II Zigbee USB stick, Sylvania on/off plug) and wireless devices (EtekCity plugs, Kasa TP-Link bulbs). I just swapped in a new X-10 CM11A interface and that didn’t seem to make any difference.

I want to deploy a 2nd gateway elsewhere but don’t want to as long as I am having problems and glitches. I was sort of hoping that version .10 would be released that would maybe address some of my issues but I’m not sure when this is going to happen.

TIA.

[Edit. The next day. It happened again. I have a Samsung Smartthings button switch configured to control two Sylvania Zigbee bulbs. I was watching today’s run log with tail -f and saw Zigbee error messages scrolling off the screen. I tried to control the bulbs with the button switch but they didn’t respond. After about a minute the error messages stopped and the bulbs responded. (Should I include the log?) This happens a lot.

I did

cat run*-16 | grep ERROR > ERRORs-16.txt

against today’s log. (6:45 AM) ERRORs-16.txt is 63K. run-app.log.2019-10-16 is 94K. The log is mostly ERROR messages.]

mstegeman · October 16, 2019, 3:15pm

@dhylands can probably speak to the Zigbee errors.

For the Etekcity device(s)… that’s a common problem with the VeSync servers, unfortunately. I see issues with mine quite frequently as well. They seem to have issues keeping their servers running.

Not sure about X10, as I’ve never used that. @AlanDThiessen is the developer of that add-on.

wlarmon · October 16, 2019, 7:02pm

Thanks for your reply.

I didn’t know that Etekcity devices required constant contact with VeSync servers. Is this true of all wireless devices? In any event I don’t think that my Etekcity plugs are causing problems. The main problem I experience is the gateway appearing to stall out for upwards of a minute after pressing an on/off switch. I have both X10 and Zigbee switches and it doesn’t make much difference which ones I am using. If the gateway is responsive, all the switches respond. If the gateway has lost its way, then none of the switches respond.

I have lights set up to turn on/off on clock time. This has worked reliably for over a month. My problems are only when using on/off switches. Well, and the logs being full of ERROR messages.

I just looked through my most recent log (about 2:15 PM) and I don’t see any X10 errors. Just info about X10 activity.

I am seeing a lot of ONVIF errors now (in addition to the Zigbee errors). I hadn’t seen any ONVIF errors until I disconnected my Amcrest camera around 9:45 AM (from mouse detection duty) to move it in front of me (so I could use it to make a new Avatar image from the Gateway ONVIF thing.) It got a flock of error messages while the camera was unplugged. But I’m still getting boatloads of ONVIF ERROR messages even after it is working (I was doing some AI cat detecting with AI-Homeguard, which worked.)

One thing that isn’t making me happy is that WebThings Gateway logs my ONVIF camera user name and password (!) in cleartext. I was logging into the camera a lot to tweak parameters so AI-Homeguard could function on my old 4 gig core 2 duo machine.

Is the gateway being non-responsive for upwards of a minute common? Or am I the only one having this problem? FWIW, my gateway is running on a Raspberry Pi 3 B.

Looking at the tail -f log, right now it is emitting Zigbee errors. The ONVIF errors have ceased, for now. I haven’t been doing anything Gateway related while composing this post. AI-Homeguard was terminated because I noticed that it was pegging the CPU. It had been running on a different computer (still on this net) overnight trying to detect a mouse. But the mouse hadn’t made an appearance, so AI-Homeguard wasn’t doing too much. (I don’t know if there is a relationship between AI-Homeguard talking to the same ONVIF camera that the Gateway is looking at.) The Gateway stalling problem predates my using AI-Homeguard.

lacojim · October 16, 2019, 11:24pm

I have similar problems with mine, also on a RPi 3B. It seems to be Zigbee related IMO. I also have the ConBee 2 device. Things will stop working for 3 to 5 minutes at time with tons of zigbee errors. This is one error I get my logs full of: ERROR : zigbee: No handler for ZDO cluster: 0001. Would be great to solve this.

wlarmon · October 17, 2019, 1:46am

I just searched my run-log file for today (8:28 PM) and ERROR : zigbee: No handler for ZDO cluster: 0001 doesn’t appear. A shortened search for ERROR : zigbee: No handler for also doesn’t appear. I don’t think mine has been unresponsive for more than a minute, though.

However, I just did

cp run*16 log-16.txt
cat log-16.txt | grep ERROR > errs-16.txt
cat log-16.txt | grep INFO > info-16.txt

log-16.txt is 1,291 KB. err-16.txt is 1,210 KB. info-16.txt is 81 KB.

Yes, it would be great to solve this.

[Edit. I just did

 cat log-16.txt | grep "ERROR  : onvif:" > onvif-16.txt

onvif-16.txt is 1,038 KB. So the majority of my ERROR log lines are ONVIF errors.]

wlarmon · October 17, 2019, 4:58pm

I didn’t want to clutter up my ~/.mozilla-iot/log/ directory anymore so I created a ~/log-look directory and wrote a simple Perl program that did

cp ~/.mozilla-iot/log/run-app.log.2019-10-17 ~/log-look/2019-10-17-0-runlog.log
cat ~/log-look/2019-10-17-0-runlog.log | grep ERROR > ~/log-look/2019-10-17-errs.log
cat ~/log-look/2019-10-17-0-runlog.log | grep INFO > ~/log-look/2019-10-17-info.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "ERROR  : onvif:" > ~/log-look/2019-10-17-errs-onvif.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "ERROR  : zigbee:" > ~/log-look/2019-10-17-errs-zigbee.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "ERROR  : x10-cm11:" > ~/log-look/2019-10-17-errs-x10-cm11.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "INFO   : onvif:" > ~/log-look/2019-10-17-info-onvif.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "INFO   : zigbee:" > ~/log-look/2019-10-17-info-zigbee.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "INFO   : x10-cm11:" > ~/log-look/2019-10-17-info-x10-cm11.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "onvif:" > ~/log-look/2019-10-17-onvif.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "zigbee:" > ~/log-look/2019-10-17-zigbee.log
cat ~/log-look/2019-10-17-0-runlog.log | grep "x10-cm11:" > ~/log-look/2019-10-17-x10-cm11.log

Which yielded

pi@gateway:~/log-look$ ll -h
total 2.9M
-rw-r--r-- 1 pi pi 756K Oct 17 12:47 2019-10-17-0-runlog.log
-rw-r--r-- 1 pi pi 583K Oct 17 12:47 2019-10-17-errs.log
-rw-r--r-- 1 pi pi 361K Oct 17 12:47 2019-10-17-errs-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 17 12:47 2019-10-17-errs-x10-cm11.log
-rw-r--r-- 1 pi pi 211K Oct 17 12:47 2019-10-17-errs-zigbee.log
-rw-r--r-- 1 pi pi 163K Oct 17 12:47 2019-10-17-info.log
-rw-r--r-- 1 pi pi  639 Oct 17 12:47 2019-10-17-info-onvif.log
-rw-r--r-- 1 pi pi  79K Oct 17 12:47 2019-10-17-info-x10-cm11.log
-rw-r--r-- 1 pi pi  62K Oct 17 12:47 2019-10-17-info-zigbee.log
-rw-r--r-- 1 pi pi 362K Oct 17 12:47 2019-10-17-onvif.log
-rw-r--r-- 1 pi pi  79K Oct 17 12:47 2019-10-17-x10-cm11.log
-rw-r--r-- 1 pi pi 272K Oct 17 12:47 2019-10-17-zigbee.log

showing that am still having a lot of errors. No X-10 errors, though.

My Perl skills are rusty but after I refresh my memory I’ll do a better program that skips grepping from the command line and does more fine grained filtering with proper Perl regexes. (Right now Perl is my language. I don’t know much about node or Python yet.)

I removed the ONVIF thing a few hours ago but I still have Zigbee, X-10, and Wi-Fi devices in the gateway.

Any suggestions for further debugging?

mstegeman · October 17, 2019, 5:51pm

It seems like the primary issue you’re having is with Zigbee devices. That’s probably related to the route discovery issues from your logs. If the Zigbee dongle struggles to find a route to a device, it cannot reliably set a property value (e.g. on/off).

Zigbee networks are self-healing, but that typically occurs when a node drops out. What I’ve seen in the past is that you should turn off your controller (the gateway) for ~15 minutes and let the network heal itself, then turn the gateway back on. Could you give that a shot?

wlarmon · October 17, 2019, 7:32pm

This helped! I shut the gateway down about 2:15 PM my time. I restarted it about 2:31 PM. This is the last

2019-10-17 14:12:19.738 ERROR  : zigbee: Confirm Status: 208: ROUTE_DISCOVERY_FAILED addr: 286d97000109813a e54b

error. But the next batch of Zigbee errors (after the restart) is

2019-10-17 14:31:21.600 ERROR  : zigbee: No handler for ZDO cluster: 0000
2019-10-17 14:31:22.099 ERROR  : zigbee: Confirm Status: 233: unknown addr: f0d1b8000010e6f1 4f7b
2019-10-17 14:31:22.102 ERROR  : zigbee: { response: true,
2019-10-17 14:31:22.104 ERROR  : zigbee:   type: 4,
2019-10-17 14:31:22.105 ERROR  : zigbee:   seqNum: 32,
2019-10-17 14:31:22.107 ERROR  : zigbee:   status: 0,
2019-10-17 14:31:22.108 ERROR  : zigbee:   payloadLen: 12,
2019-10-17 14:31:22.110 ERROR  : zigbee:   deviceState: 34,
2019-10-17 14:31:22.111 ERROR  : zigbee:   networkState: 2,
2019-10-17 14:31:22.113 ERROR  : zigbee:   dataConfirm: false,
2019-10-17 14:31:22.114 ERROR  : zigbee:   dataIndication: false,
2019-10-17 14:31:22.115 ERROR  : zigbee:   configChanged: false,
2019-10-17 14:31:22.118 ERROR  : zigbee:   dataRequest: true,
2019-10-17 14:31:22.120 ERROR  : zigbee:   id: 5,
2019-10-17 14:31:22.122 ERROR  : zigbee:   dstAddrMode: 2,
2019-10-17 14:31:22.123 ERROR  : zigbee:   destination16: '4f7b',
2019-10-17 14:31:22.125 ERROR  : zigbee:   destinationEndpoint: '01',
2019-10-17 14:31:22.127 ERROR  : zigbee:   sourceEndpoint: '01',
2019-10-17 14:31:22.129 ERROR  : zigbee:   confirmStatus: 233,
2019-10-17 14:31:22.135 ERROR  : zigbee:   extraParams: [ 0 ] }
2019-10-17 14:31:22.621 ERROR  : zigbee: No handler for ZDO cluster: 8038
2019-10-17 14:31:25.110 ERROR  : zigbee: No handler for ZDO cluster: 8038
2019-10-17 14:31:54.229 ERROR  : zigbee: No handler for ZDO cluster: 8038

Not sure what the ERROR : zigbee: No handler for ZDO cluster: 8038 error is.

But errors are now way down. I added filters for etekcity but it only had a few errors today. And still no X-10 errors. I won’t restart the ONVIF thing for now.

[Edit. There are X-10 errors but they aren’t logged as ERROR lines. Instead they are like

2019-10-17 15:26:07.134 INFO   : x10-cm11: Transaction Failed: Max attempts exceeded sending commend.

]

So maybe I should just monitor it for a while and see if the stalling problem has gone away?

lacojim · October 18, 2019, 2:55am

I tried the same thing. It did calm down for a while with Zigbee, but ONVIF is a freaking mess. It doesn’t work well with any of my 5 cameras. I have yet to even be able to watch video from a single one (all different cameras, not same brand). I removed the addon to save myself and the RPi3 from having stress lol. While this project certainly does have a bright future, it is still in infancy. Still, it is probably the most simple one of the bunch to set up quickly. I hope the v0.10 release will bring many improvements.

benfrancis · October 18, 2019, 11:56am

Hi @lacojim,

With regards to ONVIF, we can only implement what the specification says and test with the very limited number of devices we have available.

If there are specific devices that you’ve found don’t work, you’re in a great position to help us diagnose why by filing issues and sharing logs where appropriate.

We’d value your help in improving ONVIF support.

Ben

mstegeman · October 18, 2019, 4:00pm

@wlarmon I’m glad that helped! Could you open issues on the zigbee-adapter for the unknown clusters?

dhylands · October 18, 2019, 7:05pm

The 8038 error just means that we don’t have a handler for the MANAGEMENT_NETWORK_UPDATE_NOTIFY message. Obvioulsy some node (or nodes) are broadcasting these. I suspect that they’ll settle down.

wlarmon · October 18, 2019, 7:44pm

It did calm down. Today I don’t have any Zigbee errors. This is my filtered log collection as of a few minutes ago.

pi@gateway:~/log-look$ ll -h
total 124K
-rw-r--r-- 1 pi pi  26K Oct 18 15:07 2019-10-18-0-runlog.log
-rw-r--r-- 1 pi pi 3.4K Oct 18 15:07 2019-10-18-errs-etekcity.log
-rw-r--r-- 1 pi pi 3.4K Oct 18 15:07 2019-10-18-errs.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-errs-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-errs-x10-cm11.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-errs-zigbee.log
-rw-r--r-- 1 pi pi 3.4K Oct 18 15:07 2019-10-18-etekcity.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-info-etekcity.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-info-onvif.log
-rw-r--r-- 1 pi pi  22K Oct 18 15:07 2019-10-18-infos.log
-rw-r--r-- 1 pi pi 1.3K Oct 18 15:07 2019-10-18-info-x10-cm11.log
-rw-r--r-- 1 pi pi  20K Oct 18 15:07 2019-10-18-info-zigbee.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 18 15:07 2019-10-18-warns.log
-rw-r--r-- 1 pi pi 1.3K Oct 18 15:07 2019-10-18-x10-cm11.log
-rw-r--r-- 1 pi pi  20K Oct 18 15:07 2019-10-18-zigbee.log

No Zigbee errors at all today. No onvif errors because I removed that yesterday morning. As of a few minutes ago, the only errors I have are several

2019-10-18 12:22:49.857 ERROR  : etekcity: 2019-10-18 12:22:49,854 - ERROR - HTTPSConnectionPool(host='smartapi.vesync.com', port=443): Read timed out. (read timeout=5)

vesync.com connection errors, which mrstegeman previously said is a known issue with the VeSync servers.

I checked yesterday’s filtered log collection and the 8038 errors did indeed settle down yesterday. The last one was at 16:06:17.273. I had five or six after shutting the gateway down for 15 minutes yesterday around 14:15 and restarting it around 14:30.

Is needing to shutdown the gateway for 15 minutes to clear Zigbee errors a known issue and is there a fix in the pipeline? Or do I need to write a Perl script to run on crontab to periodically check for this and then send me an alert? (Perl and crontab is the limit of my programming ability at this point.)

Otherwise, I was planning on waiting a day of so to see if the Zigbee errors have stopped. Then I’ll reenable Onvif and see if it starts throwing errors again.

lacojim · October 19, 2019, 3:35am

Something I noticed tonight. When the RPi3 became really sluggish and slow to respond, it was into SWAP memory. This could very well be the entire cause, as we all know, once into SWAP, it will bring a system to its knees. It literally took 6 minutes to get logged into it when SSHing into it (after entering the PW). The first thing I did was run htop, and noticed the SWAP usage. Question is, what is using so much memory?

After rebooting the device, I am using 317MB with 0MB of SWAP.

Another thing to note, doing a #ps -ef I see that ONVIF is still loading, even though I removed it:
pi 884 714 0 04:03 ? 00:00:08 node src/addon-loader.js /home/pi/.mozilla-iot/addons/onvif-adapter

wlarmon · October 20, 2019, 7:30pm

Followup. First I don’t have either issues that @lacojim reports. My RPI 3 isn’t using swap and I never experienced a delay when logging in. And the onvif thing I removed several days isn’t showing up when I use ps -ef | grep -i onvif.

I can report that my run-app.log errors have mostly gone away. Here is what my filtered logs looked like on 2019-10-10

 
-rw-r--r-- 1 pi pi 1.7M Oct 19 08:34 2019-10-10-0-runlog.log
-rw-r--r-- 1 pi pi  29K Oct 19 08:34 2019-10-10-errs-etekcity.log
-rw-r--r-- 1 pi pi 578K Oct 19 08:34 2019-10-10-errs.log
-rw-r--r-- 1 pi pi 258K Oct 19 08:34 2019-10-10-errs-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 19 08:34 2019-10-10-errs-x10-cm11.log
-rw-r--r-- 1 pi pi 278K Oct 19 08:34 2019-10-10-errs-zigbee.log
-rw-r--r-- 1 pi pi  59K Oct 19 08:34 2019-10-10-etekcity.log
-rw-r--r-- 1 pi pi  31K Oct 19 08:34 2019-10-10-info-etekcity.log
-rw-r--r-- 1 pi pi 1.1K Oct 19 08:34 2019-10-10-info-onvif.log
-rw-r--r-- 1 pi pi 1.1M Oct 19 08:34 2019-10-10-infos.log
-rw-r--r-- 1 pi pi 8.9K Oct 19 08:34 2019-10-10-info-x10-cm11.log
-rw-r--r-- 1 pi pi 448K Oct 19 08:34 2019-10-10-info-zigbee.log
-rw-r--r-- 1 pi pi 259K Oct 19 08:48 2019-10-10-onvif.log
-rw-r--r-- 1 pi pi  23K Oct 19 08:34 2019-10-10-warns.log
-rw-r--r-- 1 pi pi 8.9K Oct 19 08:34 2019-10-10-x10-cm11.log
-rw-r--r-- 1 pi pi 725K Oct 19 08:34 2019-10-10-zigbee.log

Lots of onvif and zigbee errors. I (temporarily removed onvif errors by uninstalling the onvif adapter and eliminated the Zigbee errors when I stopped the gateway for ~15 minutes several days ago (as was suggested by @mstegeman). Today my filtered logs are

pi@gateway:~/log-look$ ll -h 2019-10-20*
-rw-r--r-- 1 pi pi  37K Oct 20 15:20 2019-10-20-0-runlog.log
-rw-r--r-- 1 pi pi 1.2K Oct 20 15:20 2019-10-20-DateTime.log
-rw-r--r-- 1 pi pi 1.9K Oct 20 15:20 2019-10-20-errs-etekcity.log
-rw-r--r-- 1 pi pi 1.9K Oct 20 15:20 2019-10-20-errs.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-errs-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-errs-x10-cm11.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-errs-zigbee.log
-rw-r--r-- 1 pi pi 1.9K Oct 20 15:20 2019-10-20-etekcity.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-info-etekcity.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-info-onvif.log
-rw-r--r-- 1 pi pi  36K Oct 20 15:20 2019-10-20-infos.log
-rw-r--r-- 1 pi pi 1.8K Oct 20 15:20 2019-10-20-info-x10-cm11.log
-rw-r--r-- 1 pi pi  26K Oct 20 15:20 2019-10-20-info-zigbee.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-onvif.log
-rw-r--r-- 1 pi pi    0 Oct 20 15:20 2019-10-20-warns.log
-rw-r--r-- 1 pi pi 1.8K Oct 20 15:20 2019-10-20-x10-cm11.log
-rw-r--r-- 1 pi pi  26K Oct 20 15:20 2019-10-20-zigbee.log

Big difference! It looks like the Zigbee errors are fixed. Now I know what to look for if the gateway starts acting up again. Thanks!

Tomorrow I reinstall onvif…

lacojim · October 20, 2019, 11:16pm

I did a fresh reinstall this morning and things seem much more stable now.

wlarmon · November 8, 2019, 1:30am

It seems like the primary issue you’re having is with Zigbee devices. That’s probably related to the route discovery issues from your logs. If the Zigbee dongle struggles to find a route to a device, it cannot reliably set a property value (e.g. on/off).

Zigbee networks are self-healing, but that typically occurs when a node drops out. What I’ve seen in the past is that you should turn off your controller (the gateway) for ~15 minutes and let the network heal itself, then turn the gateway back on. Could you give that a shot?

I’m having do this regularly now. The gateway starts acting up, I check the logs, and see a lot of Zigbee errors. Then I turn the gateway off for ~15 minutes. And then turn it on. Then the error messages go away for a while.

Is there anything I can do? Or is it something that needs to be fixed?

mstegeman · November 8, 2019, 5:09pm

Do have Zigbee devices that are added and removed frequently (e.g. powered off/on)? Are your devices far from the gateway? You might try adding some non-battery-powered devices into the network, like smart plugs, as they act as repeaters in the mesh. That’s what I had to do in my home to get things working reliably.

wlarmon · November 8, 2019, 6:43pm

My Zigbee devices are stable in that they aren’t added and removed, other than when they are first introduced to the network. I have one Zigbee smart plug. All of my Zigbee devices are within 20 feet of each other. I have four SmartThing Buttons, one Zigbee smart plug and two Zigbee smart bulbs. And four WiFi smart plugs and two Wifi smart bulbs.

As I mentioned earlier in this thread I’m using a simple Perl script that first does

cp ~/.mozilla-iot/log/run-app.log.2019-11-08 ~/log-look/2019-11-08-0-runlog.log

to get a copy of the current run-app.log.YYYY-MM-DD log copied to the ~/log-lock directory I created to hold logs that are studied. My script then does of lot of variations on

cat ~/log-look/2019-11-08-0-runlog.log | grep "ERROR  : zigbee:" > ~/log-look/2019-11-08-errs-zigbee.log

so I can look in ~/log-look to see the sizes of the filtered logs. I haven’t done this every day, but on 2019-10-28 2019-10-28-errs-zigbee.log was 0 bytes. On 2019-10-29 the corresponding log was 34 KB. And got larger every day. It was 778 K on 2019-11-06 (the day before I shut the gateway down for ~15 minutes.) Today (2019-11-08) 2019-11-08-errs-zigbee.log is 0 bytes.

So apparently the gateway will function while throwing Zigbee errors until it gets to the point where I realize that it isn’t working correctly. Usually when I use a (Zigbee) SmartThings button to turn on/off a (Zigbee) Sylvania smart bulb and I have to stab the SmartThings button repeatedly.

mstegeman · November 8, 2019, 6:52pm

The gateway operates independently of the add-ons. The Zigbee adapter just needs to initiate the network healing process periodically, which it doesn’t currently do.

It’s important to note that battery powered devices, like the SmartThings buttons, do NOT act as repeaters or routers. The Zigbee smart plug(s) and bulb(s) should, though. You just need to make sure your layout is such all devices are within a reasonable range of another non-battery-powered device (the dongle counts).