MiniUnifi intermittently failing on new (to me) iMac

Looks fine.

Code: Select all

Jan 28, 2022 at 7:20:51 AM
   miniUniFi Debug                 Unifi Controller: Updating controller
   miniUniFi Debug                 Unifi Controller: Unifi OS controller detected
   miniUniFi Debug                 Unifi Controller: UniFi Controller Getting Sites
   miniUniFi Debug                 iPhone Liz: client_data not found
   miniUniFi Debug                 iPhone Liz: Offline 00:54:40 for 3280 seconds
   miniUniFi Debug                 iPhone Mike 1: Online @ ptinsco
   Disabling plugin "miniUniFi 0.1.2"
   Stopping plugin "miniUniFi 0.1.2" (pid 55404)
   miniUniFi                       Dining Room AP: Stopping Device
   miniUniFi                       Guest Bedroom AP: Stopping Device
   miniUniFi                       iPhone Liz: Stopping Device
   miniUniFi                       iPhone Mike 1: Stopping Device
   miniUniFi                       Master Bedroom AP: Stopping Device
   miniUniFi                       Unifi Controller: Stopping Device
   miniUniFi                       Shutting down miniUniFi
   Stopped plugin "miniUniFi 0.1.2"
   Enabling plugin "miniUniFi 0.1.2"
   Starting plugin "miniUniFi 0.1.2" (pid 62213)
   Started plugin "miniUniFi 0.1.2"
   miniUniFi                       Starting miniUniFi
   miniUniFi Debug                 updateFrequency = 30.0
   miniUniFi                       Dining Room AP: Starting Device
   miniUniFi                       Guest Bedroom AP: Starting Device
   miniUniFi                       iPhone Liz: Starting Device
   miniUniFi                       iPhone Mike 1: Starting Device
   miniUniFi                       Master Bedroom AP: Starting Device
   miniUniFi                       Unifi Controller: Starting Device
   miniUniFi Debug                 Starting runConcurrentThread
   miniUniFi Debug                 Unifi Controller: Updating controller
   miniUniFi Debug                 Unifi Controller: Unifi OS controller detected
   miniUniFi Debug                 Unifi Controller: UniFi Controller Getting Sites
   miniUniFi Debug                 iPhone Liz: client_data not found
   miniUniFi Debug                 iPhone Liz: Offline for 0 seconds
   miniUniFi Debug                 iPhone Mike 1: Online @ ptinsco

Jan 28, 2022 at 7:21:49 AM
   miniUniFi Debug                 Unifi Controller: Updating controller
   miniUniFi Debug                 Unifi Controller: Unifi OS controller detected
   miniUniFi Debug                 Unifi Controller: UniFi Controller Getting Sites
   miniUniFi Debug                 iPhone Liz: client_data not found
   miniUniFi Debug                 iPhone Liz: Offline for 0 seconds
   miniUniFi Debug                 iPhone Mike 1: Online @ ptinsco

Looks like it blew up last night after I turned up the logging.

Code: Select all

2022-01-27 18:39:12.262   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:39:12.297   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:39:13.708   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:39:13.915   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:39:13.926   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:39:42.961   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:39:43.021   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:39:44.446   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:39:44.653   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:39:44.664   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:40:13.710   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:40:13.750   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:40:15.159   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:40:15.356   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:40:15.367   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:40:44.667   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:40:44.743   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:40:46.142   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:40:46.349   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:40:46.359   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:41:06.469   miniUniFi Error   Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
  File "plugin.py", line 122, in runConcurrentThread
  File "plugin.py", line 434, in updateUniFiDevice
StandardError: ServerCommunicationError -- timeout waiting for response

2022-01-27 18:41:06.469   miniUniFi Error   plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
2022-01-27 18:41:06.688   miniUniFi Debug   Starting runConcurrentThread
2022-01-27 18:41:15.662   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:41:15.706   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:41:17.078   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:41:17.302   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:41:17.313   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:41:46.682   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:41:46.745   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:41:48.109   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:41:48.348   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:41:48.359   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:42:17.196   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:42:17.243   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:42:18.617   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:42:18.843   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:42:18.855   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:43:24.539   miniUniFi Error   Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
  File "plugin.py", line 122, in runConcurrentThread
  File "plugin.py", line 434, in updateUniFiDevice
StandardError: ServerCommunicationError -- timeout waiting for response

2022-01-27 18:43:24.539   miniUniFi Error   plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
2022-01-27 18:43:24.539   miniUniFi Debug   Starting runConcurrentThread
2022-01-27 18:43:24.539   Sonos Error   Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
  File "plugin.py", line 47, in runConcurrentThread
  File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 384, in runConcurrentThread
  File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 634, in updateRelTime
StandardError: ServerCommunicationError -- timeout waiting for response

2022-01-27 18:43:24.540   Sonos Error   plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
2022-01-27 18:43:24.540   AD2USB Alarm Interface Error   Error on line 749
2022-01-27 18:43:24.540   AD2USB Alarm Interface Error   panelMsgRead: Error: ServerCommunicationError -- timeout waiting for response
2022-01-27 18:43:24.540   AD2USB Alarm Interface Error   Error on line 749
2022-01-27 18:43:24.540   AD2USB Alarm Interface Error   panelMsgRead: Error: ServerCommunicationError -- timeout waiting for response
2022-01-27 18:43:24.540   miniUniFi Error   Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
  File "plugin.py", line 112, in runConcurrentThread
StandardError: ServerCommunicationError -- timeout waiting for response

2022-01-27 18:43:24.540   miniUniFi Error   plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
2022-01-27 18:43:24.540   miniUniFi Debug   Starting runConcurrentThread
2022-01-27 18:43:24.542   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:43:24.547   Sonos   SoCo Reactor Ignition...
2022-01-27 18:43:24.607   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:43:26.092   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:43:26.303   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:43:26.313   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:43:48.441   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:43:48.495   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:43:49.945   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:43:50.143   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:43:50.153   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco
2022-01-27 18:44:19.268   miniUniFi Debug   Unifi Controller: Updating controller
2022-01-27 18:44:19.312   miniUniFi Debug   Unifi Controller: Unifi OS controller detected
2022-01-27 18:44:20.674   miniUniFi Debug   Unifi Controller: UniFi Controller Getting Sites
2022-01-27 18:44:20.880   miniUniFi Debug   iPhone Liz: Online @ ptinsco
2022-01-27 18:44:20.891   miniUniFi Debug   iPhone Mike 1: Online @ ptinsco

I'm not convinced that it's miniUniFi is causing the issue. I think it's just the first one to run into it because of the rate of updates. Two other plugins report it immediately after.

If you restart just the miniUniFi plugin, do all the errors stop?

The errors don’t happen often enough to be able to answer that question. They can happen from every couple of hours to every couple of days. I can dial back the miniUnifi frequency to see if that helps. BUT if I turn miniUnifi off, the system runs for literally weeks without a blip.

Interesting. Let me look at a few things.

Put another way just for clarity, I have never seen this error when miniUnifi isn’t running.

I've reset the miniUnifi frequency to 600 seconds and restarted it just in case. I'll let you know what happens.

Please install the pre-release at https://github.com/FlyingDiver/Indigo-m ... /tag/0.1.3

And set the poll frequency back to where you had it.

Done. I'll let you know how it goes.

So far, no string of failures similar to what was happening before. Something new that I do see is this:

2022-02-02 03:49:36.683 miniUniFi Debug Unifi Controller: Updating controller
2022-02-02 03:49:36.724 miniUniFi Debug Unifi Controller: Unifi OS controller detected
2022-02-02 03:49:38.111 miniUniFi Debug Unifi Controller: UniFi Controller Getting Sites
2022-02-02 03:49:38.369 miniUniFi Debug iPhone Liz: Online @ ptinsco
2022-02-02 03:49:38.380 miniUniFi Debug iPhone Mike 1: Online @ ptinsco
2022-02-02 03:50:07.571 miniUniFi Debug Unifi Controller: Updating controller
2022-02-02 03:50:07.614 miniUniFi Debug Unifi Controller: Unifi OS controller detected
2022-02-02 03:50:12.774 miniUniFi Error UniFi Controller Login Connection Error: HTTPSConnectionPool(host='192.168.0.2', port=443): Read timed out. (read timeout=5.0)
2022-02-02 03:50:12.787 miniUniFi Debug iPhone Liz: Online @ ptinsco
2022-02-02 03:50:12.799 miniUniFi Debug iPhone Mike 1: Online @ ptinsco
2022-02-02 03:50:37.723 miniUniFi Debug Unifi Controller: Updating controller
2022-02-02 03:50:37.771 miniUniFi Debug Unifi Controller: Unifi OS controller detected
2022-02-02 03:50:39.363 miniUniFi Debug Unifi Controller: UniFi Controller Getting Sites
2022-02-02 03:50:39.589 miniUniFi Debug iPhone Liz: Online @ ptinsco
2022-02-02 03:50:39.600 miniUniFi Debug iPhone Mike 1: Online @ ptinsco

Is this helpful?

I might need to tweak that timeout if logins consistently take more than 5 seconds.
But it doesn't look like it's every time, so maybe just leave it alone.

It only happened this one time over the last 5 days. Is this related to the previous issue and/or the change you made to the plugin?

It only happened this one time over the last 5 days. Is this related to the previous issue and/or the change you made to the plugin?

I added timeouts to make sure it didn't hang waiting for the controller to respond. Which was to hopefully fix the previous issue. So it's saying that on this particular polling cycle (to get current status from the controller), the controller didn't respond promptly. But when it retried 5 seconds later, it worked fine. So all good. If those start happening frequently, you have a network problem or the controller is failing.

Awesome. I just grep'd the logs going back to January 5th, and this is the one and only time this "Login Connection Error" has happened. So I'm considering it a fluke.

I'll continue to keep an eye on things, but so far your timeouts seem to be doing the trick regarding the issue related to this thread.

Thanks,
Mike

Blew up again. Unfortunately I had already reduced the logging. Same failure mode as before. MiniUnifi experiences the issue and then a chain of plugins fail immediately afterwards.

Feb 6, 2022 at 4:41:59 PM
Z-Wave received "Garage Temp" sensor update to 50.7 °F

Feb 6, 2022 at 4:47:53 PM
Z-Wave received "016 - Garage Temp" status update battery level 50%

Feb 6, 2022 at 4:54:45 PM
miniUniFi Error Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
File "plugin.py", line 121, in runConcurrentThread
StandardError: ServerCommunicationError -- timeout waiting for response

miniUniFi Error plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
Sonos Error Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
File "plugin.py", line 47, in runConcurrentThread
File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 384, in runConcurrentThread
File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 634, in updateRelTime
StandardError: ServerCommunicationError -- timeout waiting for response

Sonos Error plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
AD2USB Alarm Interface Error Error on line 749
AD2USB Alarm Interface Error panelMsgRead: Error: ServerCommunicationError -- timeout waiting for response
Sonos SoCo Reactor Ignition...
AD2USB Alarm Interface Error Error on line 749
AD2USB Alarm Interface Error panelMsgRead: Error: ServerCommunicationError -- timeout waiting for response
Sonos Error Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
File "plugin.py", line 47, in runConcurrentThread
File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 384, in runConcurrentThread
File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Sonos.indigoPlugin/Contents/Server Plugin/Sonos.py", line 634, in updateRelTime
StandardError: ServerCommunicationError -- timeout waiting for response

Sonos Error plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
Ecobee 2 Error Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
File "plugin.py", line 198, in runConcurrentThread
File "/Library/Application Support/Perceptive Automation/Indigo 2021.2/Plugins/Ecobee 2.indigoPlugin/Contents/Server Plugin/ecobee_account.py", line 142, in server_update
StandardError: ServerCommunicationError -- timeout waiting for response

Ecobee 2 Error plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
miniUniFi Error Error in plugin execution runConcurrentThread:

Traceback (most recent call last):
File "plugin.py", line 111, in runConcurrentThread
File "plugin.py", line 203, in updateUniFiController
KeyError: 'key port not found in dict'

miniUniFi Error plugin runConcurrentThread function returned or failed (will attempt again in 10 seconds)
Sonos SoCo Reactor Ignition...

Feb 6, 2022 at 4:56:13 PM
Indigo Cocoa client disconnected (192.168.0.13)

Feb 6, 2022 at 5:04:55 PM
Z-Wave received "Basement - Temperature" sensor update to 60.8 °F

Feb 6, 2022 at 5:20:19 PM
Trigger Guest Bath Off

Feb 6, 2022 at 5:24:23 PM
Trigger Sunset - Foyer Lights
Trigger Sunset - Living Room Lights
Lutron RRA2/Caséta Foyer Pendant: Set brightness to 75 with fade 5
Lutron RRA2/Caséta Great Room - Dimmer 49 - Living Room Recessed: Set brightness to 50 with fade 5