Announcement

Collapse
No announcement yet.

High CPU Load?

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    High CPU Load?

    I updated to the newest version of the plugin last night on my Raspberry Pi 4 (running HS3) and quite getting communication to my MQTT broker. I've restarted my system multiple times. This morning the web interface would barely load so I logged in am seeing this type of CPU load from the plugin. Any thoughts to what is going on?
    Click image for larger version  Name:	Annotation 2020-07-09 084552.png Views:	0 Size:	186.2 KB ID:	1400956

    Update: I restarted just the plugin and not the whole system and it seems to have cleared.

    #2
    There was discussion in the Hubitat forum about a user needing to selectively enable some plugins after restart. Seems to be related to HS/System unable to handle the multiple high-load (initialization) applications.

    One suggestion is the setting on the General tab for enumeration of HS devices. HS object access has a high CPU burden so if you have many HS devices then the startup could be a burden. Make the setting so that enumeration only occurs on use of the button. Since the list of HS devices does not change very often so don't really need to do it on every startup.

    Currently mcsMQTT has two phases of initialization. After the first it indicates to HS that init is complete. I'm thinking it may be better to have three phases where the first phase is just some very basic things.

    Comment


      #3
      Great, thanks. Will make that change.

      Comment


        #4
        I did the change for three phase initialization. It is at http://mcsSpirnklers.com/mcsMQTT_5_4_0_0.zip. HSPI_MCSMQTT.exe goes in the HS folder. mcsMQTT_2020.dll goes in \bin\mcsMQTT folder.

        From the manual ...

        Startup of the plug-in establishes a connection with HS and makes HS aware of the capabilities provided by the plugin. The plug-in then performs a connection to the MQTT Broker or spawns its own MQTT Broker is one has not been specified. It also does its bookkeeping of MQTT topics and HS Devices that have been previously observed. During this time it will queue any inbound requests to send MQTT messages as well as defer rendering of browser pages until it completes initialization.
        As a user with longer initialization and a browser page is requested at startup from mcsMQTT then it will wait until initialization is complete before delivering it. If requests are made during the initialization time to send MQTT messages the plug-in will queue the request and send them when initialization is complete.

        This change removes timing dependency at startup so HS restarts should be more graceful. The total startup time will depend upon how many plugins are competing for CPU resources at the same time.

        Comment


          #5
          Just for others there was a misspelling somewhere : http://mcssprinklers.com/mcsMQTT_5_4_0_0.zip . I Just took an old link and replaced 5_4_0_0

          Comment


            #6
            Ok i remember now why i downgraded the plugin to v 5.3.3.4. I think the issue started at v 5.3.3.5 OR 5.3.4.0.

            The plugin is constantly restarting :

            Code:
             
            7/10/2020 00:21:56
            HomeSeer Starting Plug-In Plugin mcsMQTT started successfully in 124 milliseconds
            7/10/2020 00:21:56
            HomeSeer Starting Plug-In Initializing plugin mcsMQTT ...
            7/10/2020 00:21:56
            HomeSeer Starting Plug-In mcsMQTT loaded in 15012 milliseconds
            7/10/2020 00:21:41
            HomeSeer Info Plugin mcsMQTT has connected. IP:127.0.0.1:54130
            7/10/2020 00:21:41
            HomeSeer Warning I/O interface mcsMQTT is down, executable is not running, restarting ...
            7/10/2020 00:21:16
            HomeSeer Info Plugin mcsMQTT with ID: and Instance: has disconnected
            7/10/2020 00:20:11
            HomeSeer Starting Plug-In Plugin mcsMQTT started successfully in 135 milliseconds
            7/10/2020 00:20:11
            HomeSeer Starting Plug-In Initializing plugin mcsMQTT ...
            7/10/2020 00:20:11
            HomeSeer Starting Plug-In mcsMQTT loaded in 15013 milliseconds
            7/10/2020 00:19:56
            HomeSeer Info Plugin mcsMQTT has connected. IP:127.0.0.1:54080
            7/10/2020 00:19:56
            HomeSeer Warning I/O interface mcsMQTT is down, executable is not running, restarting ...
            7/10/2020 00:19:30
            HomeSeer Info Plugin mcsMQTT with ID: and Instance: has disconnected
            7/10/2020 00:18:26
            HomeSeer Starting Plug-In Plugin mcsMQTT started successfully in 138 milliseconds
            7/10/2020 00:18:25
            HomeSeer Starting Plug-In Initializing plugin mcsMQTT ...
            7/10/2020 00:18:25
            HomeSeer Starting Plug-In mcsMQTT loaded in 15017 milliseconds
            7/10/2020 00:18:10
            HomeSeer Info Plugin mcsMQTT has connected. IP:127.0.0.1:54010
            7/10/2020 00:18:10
            HomeSeer Warning I/O interface mcsMQTT is down, executable is not running, restarting ...
            7/10/2020 00:18:03
            HomeSeer Info Plugin mcsMQTT with ID: and Instance: has disconnected
            7/10/2020 00:16:58
            HomeSeer Plug-In Finished initializing plug-in mcsMQTT
            7/10/2020 00:16:58
            HomeSeer Starting Plug-In mcsMQTT loaded in 600 milliseconds
            7/10/2020 00:16:57
            HomeSeer Starting Plug-In Plugin mcsMQTT started successfully in 134 milliseconds
            7/10/2020 00:16:57
            HomeSeer Starting Plug-In Initializing plugin mcsMQTT ...
            7/10/2020 00:16:57
            HomeSeer Info Plugin mcsMQTT has connected. IP:127.0.0.1:53716
            7/10/2020 00:16:53
            HomeSeer Plug-In Found plug-in: mcsMQTT, version: 5.4.0.0
            V 5.3.3.4 runs fine here.

            Let me know if you want me test a more recent version and send you any logs

            Comment


              #7
              HS is monitoring something, but don't know what specific monitor is being used.


              7/10/2020 00:19:30 HomeSeer Warning I/O interface mcsMQTT is down, executable is not running, restarting ...
              7/10/2020 00:18:26 HomeSeer Info Plugin mcsMQTT with ID: and Instance: has disconnected
              The code sequence below was taken from the HS3 sample plugin and would seem to be what is being monitored. It really has little to do with the actual plugin operation, but only that a socket connection exists. Do you have a console window that shows any awareness that the plugin has disconnected?

              Code:
              Try
              ' connect to HS so it can register a callback to us
              host.Connect(PLUGIN_NAME, instance)
              
              ' create the user object that is the real plugin, accessed from the pluginAPI wrapper
              callback = callback
              hs = host
              
              Console.WriteLine("Connected, waiting to be initialized...")
              
              Do
                Threading.Thread.Sleep(10)
              Loop While client.CommunicationState = HSCF.Communication.Scs.Communication.CommunicationStates.Connected
              
              Console.WriteLine("Connection lost, exiting")
              ' disconnect from server for good here
              client.Disconnect()
              clientCallback.Disconnect()
              wait(2)
              End
              
              Catch ex As Exception
              Console.WriteLine("Cannot connect(2): " & ex.Message)
              wait(2)
              Return
              End Try
              The changes made in the versions you identified as the breaking point apply to the internal broker and to additional Shelly devices. Are you using the internal broker? If so you will be getting heartbeat messages in the console.

              I have been doing all my work on Windows. I will load up a HS4 install instance on a Linux to see if I get any differences.

              Comment


                #8
                I install HS4 4.1.1.0 and mcsMQTT 5.4.0.1 on Linux and ran for 30 minute test and normal operation, no restarts, and low CPU utilization. I manually stopped it from HS plugin menu and then restarted it. The shutdown sequence and startup sequence looks proper. I also did an evaluation on the HS4 plugin of same version on Windows and again no unexpected behaviors.

                Click image for larger version

Name:	Capture1.PNG
Views:	49
Size:	45.5 KB
ID:	1401419

                Click image for larger version

Name:	Capture.PNG
Views:	72
Size:	79.3 KB
ID:	1401418

                Comment


                  #9
                  Thanks. Here I do not have the cpu load issue , Do you need me to do anything To catch something for the other one?

                  Here i am using mosquitto broker at 127.0.0.1

                  Comment


                    #10
                    Micheal here are some logs from the console ( plugin V 5.4.0.1)

                    Code:
                    ShutdownIO
                    Plugin shut down, killing EXE...
                    Connection lost, exiting
                    Disconnected from server - client
                    05:01:08:2072:[Info]->Plugin mcsMQTT with ID: and Instance: has disconnected
                    Stat parse exception: Value was either too large or too small for an Int16.
                    Error in IsEXERunning: Can't find process with ID 0
                    Verifying plugin links...
                    Done removing plugin.
                    Writing events, serializing start...
                    Writing events, done serializing, elapsed MS: 230
                    Plugin: mcsMQTT Instance: starting...
                    Connecting to server at 127.0.0.1...
                    05:01:35:0624:[Info]->Plugin mcsMQTT has connected. IP:127.0.0.1:40010
                    Connected, waiting to be initialized...
                    05:01:35:1785:[Starting Plug-In]->Initializing plugin mcsMQTT ...
                    Initializing
                    05:01:35:2131:[mcsMQTT]->Version 5.4.0.1 Registered with Homeseer
                    05:01:35:3127:[Starting Plug-In]->Plugin mcsMQTT started successfully in 134 milliseconds
                    05:01:35:3545:[Starting Plug-In]->mcsMQTT loaded in 500 milliseconds
                    05:01:35:3546:[Plug-In]->Finished initializing plug-in mcsMQTT
                    Initialization Complete
                    05:01:40:3586:[mcsMQTT]->MQTTClient is Connected to broker 1 at 127.0.0.1
                    Restart Broker
                    05:02:40:3640:[mcsMQTT]->Spawning Internal MQTT Broker
                    05:02:40:3648:[mcsMQTT]->Internal MQTT Broker restarted. Last heartbeat received at 1/1/0001 12:00:00 AM
                    Heartbeat 7/10/2020 5:02:40 PM
                    
                    Unhandled Exception:
                    System.Net.Sockets.SocketException (0x80004005): An address incompatible with the requested protocol was used
                    at System.Net.Sockets.Socket..ctor (System.Net.Sockets.AddressFamily addressFamily, System.Net.Sockets.SocketType socketType, System.Net.Sockets.ProtocolType protocolType) [0x00069] in <4e15bbae9d7043d8afd6cfd50bd9bd5a>:0
                    at System.Net.Sockets.TcpListener..ctor (System.Net.IPAddress localaddr, System.Int32 port) [0x00046] in <4e15bbae9d7043d8afd6cfd50bd9bd5a>:0
                    at mcs.Networking.M2Mqtt.Communication.MqttTcpCommunicationLaye r.ListenerThread () [0x0000d] in <db57d72967914dabb195d71cb417ce80>:0
                    at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ThreadHelper.ThreadStart () [0x00008] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    [ERROR] FATAL UNHANDLED EXCEPTION: System.Net.Sockets.SocketException (0x80004005): An address incompatible with the requested protocol was used
                    at System.Net.Sockets.Socket..ctor (System.Net.Sockets.AddressFamily addressFamily, System.Net.Sockets.SocketType socketType, System.Net.Sockets.ProtocolType protocolType) [0x00069] in <4e15bbae9d7043d8afd6cfd50bd9bd5a>:0
                    at System.Net.Sockets.TcpListener..ctor (System.Net.IPAddress localaddr, System.Int32 port) [0x00046] in <4e15bbae9d7043d8afd6cfd50bd9bd5a>:0
                    at mcs.Networking.M2Mqtt.Communication.MqttTcpCommunicationLaye r.ListenerThread () [0x0000d] in <db57d72967914dabb195d71cb417ce80>:0
                    at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    at System.Threading.ThreadHelper.ThreadStart () [0x00008] in <a17fa1457c5d44f2885ac746c1764ea5>:0
                    05:02:40:3806:[Info]->Plugin mcsMQTT with ID: and Instance: has disconnected
                    Stat parse exception: Value was either too large or too small for an Int16.
                    Error in IsEXERunning: Can't find process with ID 0
                    05:03:05:3970:[Warning]->I/O interface mcsMQTT is down, executable is not running, restarting ...
                    Plugin: mcsMQTT Instance: starting...
                    Connecting to server at 127.0.0.1...
                    05:03:05:6241:[Info]->Plugin mcsMQTT has connected. IP:127.0.0.1:40036
                    Connected, waiting to be initialized...
                    05:03:20:4230:[Starting Plug-In]->mcsMQTT loaded in 15013 milliseconds
                    05:03:20:6272:[Starting Plug-In]->Initializing plugin mcsMQTT ...
                    Initializing
                    05:03:20:6641:[mcsMQTT]->Version 5.4.0.1 Registered with Homeseer
                    05:03:20:7659:[Starting Plug-In]->Plugin mcsMQTT started successfully in 138 milliseconds
                    Checking plugin health 7/10/2020 5:03:24 PM
                    UPNP starting scan
                    UDPListener start
                    Initialization Complete

                    Comment


                      #11
                      is the internal mcsmqtt broker starting at the same time of my local ( external mosquitto) one ?
                      Attached Files

                      Comment


                        #12
                        Depends upon the startup scheduling. If they are both on the same computer then one will loose the race to claim port 1883. One one broker per computer is allowed by the OS unless the brokers use different ports.

                        The console shows that mosquitto won the startup timing race. When mcsMQTT tried to launch it failed
                        05:02:40:3648:[mcsMQTT]->Internal MQTT Broker restarted. Last heartbeat received at 1/1/0001 12:00:00 AM Heartbeat 7/10/2020 5:02:40 PM
                        I know within mcsMQTT there is a difference between 127.0.0.1 and blank for the broker, but at some point the blank gets converted to 127.0.0.1. I need to see where this happens as I had not considered a user entering 127.0.0.1 to indicate an external broker. I also did not expect exception. Hopefully I can repeat it as well and deal with it.

                        Comment


                          #13
                          Thanks Michael!!

                          Comment


                            #14
                            http://mcsSprinklers.com/HSPI_mcsMQTT_5_4_0_2.zip has the logic update for 127.0.0.1 (external) vs. null (internal) for the MQTT broker. Should be uploaded by 4:30 Pacific.

                            Comment


                              #15
                              Thanks . is that the hs3 or hs4 version?

                              I just loaded http://mcssprinklers.com/mcsMQTT_5_4_0_2.zip to be sure .

                              Comment

                              Working...
                              X