Event callback errors in log

[simonmason]

Hi Steve,

I am in the process of diagnosing an issue with my system and I turned the log level to 2 to monitor events. As soon as I did this I noticed the log was full of event callback errors. I started diagnosing this by disabling plugins and the issue comes and goes when I enable the SDJ-Health plugin. I am assuming something is gone awry in my setup. I checked everything out, increased the log level, etc. but couldn't see any error message etc.

Happy to post more information to help in the diagnosis on this? Thanks.

[SteveMSJ]

Hi Steve,

I am in the process of diagnosing an issue with my system and I turned the log level to 2 to monitor events. As soon as I did this I noticed the log was full of event callback errors. I started diagnosing this by disabling plugins and the issue comes and goes when I enable the SDJ-Health plugin. I am assuming something is gone awry in my setup. I checked everything out, increased the log level, etc. but couldn't see any error message etc.

Happy to post more information to help in the diagnosis on this? Thanks.

Hi
That's not an issue I have encountered or had reported before.

Perhaps as a starting point for troubleshooting post your system details.

Where are you setting the log level to 2?

Can you post the callback error? Does it give any clue as to where it comes from?

Steve

[simonmason]

Here is my system info:

Current Date/Time: 4/6/2021 4:27:13 PM
HomeSeer Version: HS3 Standard Edition 3.0.0.548
Operating System: Microsoft Windows 10 Pro - Work Station
System Uptime: 0 Days 5 Hours 20 Minutes 7 Seconds
IP Address: 192.168.2.70
Number of Devices: 1681
Number of Events: 1441
Available Threads: 800
HSTouch Enabled: True
Event Threads: 2
Event Trigger Eval Queue: 0
Event Trigger Priority Eval Queue: 0
Device Exec Queue: 0
HSTouch Event Queue: 0
Email Send Queue: 0
Anti Virus Installed: Norton Security Windows Defender
In Virtual Machine: No MFG: asustek computer inc.
Enabled Plug-Ins
2.0.61.0: BLBackup
3.0.38.0: BLLock
2.0.37.0: BLML2HS
2.0.37.0: BLRoombaWifi
2.0.26.0: BLUPS
3.4.1.0: Caddx
0.0.0.32: drhsIpPlugIn
3.0.0.73: EasyTrigger
5.0.0.59: Global Cache Pro
3.24.326.10: HSBuddy
3.4.0.3: Hubitat
2.1.1.10: JowiHue
3.2.0.10: MeiKu
3.0.0.34: Nest
0.0.0.52: Pushover 3P
30.0.0.41: RFXCOM
3.0.4.9: Tasker Plugin
3.0.0.2: UPB
3.0.2.0: Z-Wave

I am setting the log debug level in homeseer to 2 - Event tracking. I did try playing with the log level in the sdj-health plugin but didn't see any changes in the log. But I wasn't looking that closely.

Here is the error message:

Dropping event callbacks due to full queue (Type: LOG) (2000 entries), system may be too busy, plugins and HSTouch may not receive all device updates

This starts up repeatedly in the log as soon as I turn on the plugin.

I get this in-between in the log:

Apr-06 16:36:02

EVENT DEBUG

04:36:02:9085: Calling event LOG callback for plug-in SDJ-Health

Apr-06 16:36:02

EVENT DEBUG

04:36:02:9065: Calling event LOG callback for plug-in SDJ-Health Complete, time: 0 ms

And a lot - turning on the plugin causes hundreds if not thousands of these calls in the log within seconds. Again, this is at the level 2 log event tracking in homeseer. Thanks.

[SteveMSJ]

I am setting the log debug level in homeseer to 2 - Event tracking. I did try playing with the log level in the sdj-health plugin but didn't see any changes in the log. But I wasn't looking that closely.

Here is the error message:

Dropping event callbacks due to full queue (Type: LOG) (2000 entries), system may be too busy, plugins and HSTouch may not receive all device updates

This starts up repeatedly in the log as soon as I turn on the plugin.

I get this in-between in the log:

Apr-06 16:36:02

EVENT DEBUG

04:36:02:9085: Calling event LOG callback for plug-in SDJ-Health

Apr-06 16:36:02

EVENT DEBUG

04:36:02:9065: Calling event LOG callback for plug-in SDJ-Health Complete, time: 0 ms

And a lot - turning on the plugin causes hundreds if not thousands of these calls in the log within seconds. Again, this is at the level 2 log event tracking in homeseer. Thanks.

What is happening there is that you are creating an infinite loop in HS. This will happen with any plug-in that monitors the log if you set that debug level in Homeseer.
There was a thread about this last year that you participated in where you were having problems with your system and the same issue came up of creating an infinite loop by setting the HS event debugging.
https://forums.homeseer.com/forum/ho...r-on-460/page3

Each time there is a log message a callback is made to the plug-in and also HS creates another EVENT DEBUG log message, which creates another callback, which creates another EVENT DEBUG message, and on and on and on...

Before setting that debug level in HS you must turn off all plug-ins that are registered to receive log message events.

Steve

[simonmason]

Well how about that - makes perfect sense. The issue back in 2018 was slightly different. It was not related to the increased debug log level but was happening in normal usage.

They released a new version that started reporting when it got backed up. Before that it just got overloaded. We all thought this was new when in fact it had already been an issue but didn’t report it.

I was getting close to figuring this out as the ultralog plug-in was also causing the same issue.

Thanks for helping me figure this out.

[SteveMSJ]

Well how about that - makes perfect sense. The issue back in 2018 was slightly different. It was not related to the increased debug log level but was happening in normal usage.

They released a new version that started reporting when it got backed up. Before that it just got overloaded. We all thought this was new when in fact it had already been an issue but didn’t report it.

I was getting close to figuring this out as the ultralog plug-in was also causing the same issue.

Thanks for helping me figure this out.

No problem.

Best of luck sorting your issues. I doubt SDJ-Health is causing your callback errors, as there are loads of users without issues. However, if you need any help troubleshooting please post back.

The most likely cause is rapid device changes from timer devices with lots of plug-ins registered for device change callbacks.

Steve

[simonmason]

Not your issue. Thanks. It does appear that turning on debug level 2 is largely useless in homeseer if you have anything substantive going on in the server. The log just seems to back up and chokes.

[SteveMSJ]

Not your issue. Thanks. It does appear that turning on debug level 2 is largely useless in homeseer if you have anything substantive going on in the server. The log just seems to back up and chokes.

I seem to remember a couple of us requested that HS log the debug level 2 messages to a file instead of the log to prevent the infinite loop, but it didn't get implemented. You can debug other plug-ins using this but you have to make sure you have any plug-ins that monitor the log disabled.

Steve