Announcement

Collapse
No announcement yet.

Imperihome crashing at startup

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

    Imperihome crashing at startup

    When it rains it pours? Ive had Imperihome disabled for a while for performance reasons (not in the plugin, but had a number of plugins turned off due to high CPU usage in some others that are more critical). Now that I've gotten updates for a few that has freed up so much CPU, I went ahead and tried to re-enable Imperihome. However I get this at each attempt:

    Initializing plug-in(2): ImperiHome Instance::Object reference not set to an instance of an objectSTACK: at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke (System.Runtime.Remoting.Proxies.RealProxy rp, System.Runtime.Remoting.Messaging.IMessage msg, System.Exception& exc, System.Object[]& out_args) [0x00108] in <15c986724bdc480293909469513cfdb3>:0 at (wrapper managed-to-native) System.Object.__icall_wrapper_mono_remoting_wrapper(intptr,i ntptr) at (wrapper remoting-invoke) HomeSeerAPI.IPlugInAPI.InitIO(string) at Scheduler.clsHSPI.CheckInterfaces () [0x000c4] in <9cbd571841f34b1e9a00b22393b8dea6>:0

    Anything I can do to try and help you track this one down? No config page of course since the plugin dies, but if I can turn on login in an INI file or anywhere else or do any other tests please just let me know.

    #2
    in ImperiHome.ini add:

    [GENERAL]
    log_level=Trace

    You might also want to remove everything else in there to test.

    Comment


      #3
      Where is the log file written,I don't see anything being created in the Logs directory.

      Comment


        #4
        with only this line added to the logs, it doesn't create a log file, the logs are just written to HS logs.

        if you want a log file, add:

        [GENERAL]
        log_level=Trace
        log_to_file_enabled=True
        file_log_level=Trace

        Comment


          #5
          Originally posted by spud View Post
          with only this line added to the logs, it doesn't create a log file, the logs are just written to HS logs.

          if you want a log file, add:

          [GENERAL]
          log_level=Trace
          log_to_file_enabled=True
          file_log_level=Trace
          Spud, I apologize but I have enabled those settings. I do still se a startup message in the HS log as well as the same exception (copied below), but I am not seeing any log file being created. I checked the HS root dir, the Logs dir, html dir tree. Anywhere else I should look?

          Initializing plug-in(2): ImperiHome Instance::Object reference not set to an instance of an objectSTACK: at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke (System.Runtime.Remoting.Proxies.RealProxy rp, System.Runtime.Remoting.Messaging.IMessage msg, System.Exception& exc, System.Object[]& out_args) [0x00108] in <15c986724bdc480293909469513cfdb3>:0 at (wrapper managed-to-native) System.Object.__icall_wrapper_mono_remoting_wrapper(intptr,i ntptr) at (wrapper remoting-invoke) HomeSeerAPI.IPlugInAPI.InitIO(string) at Scheduler.clsHSPI.CheckInterfaces () [0x000c4] in <9cbd571841f34b1e9a00b22393b8dea6>:0

          Here is the timing info, which may be useful to help narrow down where this is occurring. Clearly you can register your links, get a device enumerator, etc so you're pretty far along in init when the crash occurs. You do spend 8 minutes in that set of capi calls which matches what I see. The plugin stays at initialization pending for a long time and then I see the exception towards the (apparent) end of startup.

          Total timings for HSPI_ImperiHome at 9/14/2019 3:13:25 PM
          Timing: HSPI_ImperiHome.IAppCallbackAPI.RegisterConfigLink Total Calls: 1 Invoke: 69ms Deserialization: 0ms Total: 70ms Average: 70ms
          Timing: HSPI_ImperiHome.IAppCallbackAPI.RegisterLink Total Calls: 3 Invoke: 283ms Deserialization: 1ms Total: 284ms Average: 94ms
          Timing: HSPI_ImperiHome.IHSApplication.CAPIGetSingleControlByUse Total Calls: 6223 Invoke: 503,547ms Deserialization: 2,873ms Total: 506,421ms Average: 81ms
          Timing: HSPI_ImperiHome.IHSApplication.Connect Total Calls: 1 Invoke: 432ms Deserialization: 4ms Total: 436ms Average: 436ms
          Timing: HSPI_ImperiHome.IHSApplication.GetDeviceEnumerator Total Calls: 1 Invoke: 18,815ms Deserialization: 25,249ms Total: 44,064ms Average: 44,064ms
          Timing: HSPI_ImperiHome.IHSApplication.GetINISetting Total Calls: 20 Invoke: 1,997ms Deserialization: 5ms Total: 2,003ms Average: 100ms
          Timing: HSPI_ImperiHome.IHSApplication.RegisterHelpLink Total Calls: 1 Invoke: 97ms Deserialization: 0ms Total: 98ms Average: 98ms
          Timing: HSPI_ImperiHome.IHSApplication.RegisterPage Total Calls: 1 Invoke: 145ms Deserialization: 0ms Total: 145ms Average: 145ms
          Timing: HSPI_ImperiHome.IHSApplication.WriteLog Total Calls: 1 Invoke: 59ms Deserialization: 0ms Total: 59ms Average: 59ms
          Timing: HSPI_ImperiHome.IHSApplication.get_APIVersion Total Calls: 1 Invoke: 264ms Deserialization: 119ms Total: 384ms Average: 384ms

          Comment


            #6
            The log file is written to the Logs directory, you should at least see the startup message with the version of the plugin

            I guess the problem is that the InitIO call takes a lot of time and may hit the 8 minutes timeout you talked about.
            In version 3.0.0.35, I moved that logic to its own thread.

            Comment


              #7
              Originally posted by spud View Post
              The log file is written to the Logs directory, you should at least see the startup message with the version of the plugin

              I guess the problem is that the InitIO call takes a lot of time and may hit the 8 minutes timeout you talked about.
              In version 3.0.0.35, I moved that logic to its own thread.
              Im sorry i should have put that together! Yep that certainly would explain it. I’m traveling today but will try the update by tomorrow and report back. Much appreciated.

              Comment


                #8
                I don't see .35 in the updater (beta or otherwise) so Ill check again tomorrow. Thanks

                Comment


                  #9
                  it's in the beta section, I've just checked and I can install it.

                  Comment


                    #10
                    Originally posted by spud View Post
                    it's in the beta section, I've just checked and I can install it.
                    Spud, I simply can't find it. I thought maybe a version of the update file got cached somewhere, so checked again today. It is not showing. Are you sure you set Linux as a platform when you setup the beta? Maybe its only showing to Windows users?


                    Click image for larger version

Name:	Screen Shot 2019-09-16 at 10.18.37 AM.png
Views:	141
Size:	388.3 KB
ID:	1326861

                    Comment


                      #11
                      bsobel I found it and updated it this morning. I'm running HS on Windows, so looks like your assumption about it not being set as linux compatible is correct.
                      HS 3.0.0.548: 1990 Devices 1172 Events
                      Z-Wave 3.0.1.262: 126 Nodes on one Z-Net

                      Comment


                        #12
                        It is set as compatible with Linux, but there is a bug in the portal developer that makes it impossible to provide a different zip for Linux for a Beta version.

                        Anyway, you can download it from http://homeseer.com/updates3rd3/Impe...x_3-0-0-35.zip
                        To install just overwrite your current HSPI_ImperiHome.exe file in the HS3 dir.

                        Comment


                          #13
                          The plugin starts, the config page gets registered. However I am getting empty 'error' on an otherwise empty web page when I try to go to http://ip/imperihomeconfig I suspect the background init you mentioned is still running, so Ill try again in 20-30 mins and see if the error only occurs until that scan completes or is a new or separate issue.

                          Got this in the log at the same time:
                          Sep-16 6:31:32 PM ImperiHome ERROR Object reference not set to an instance of an object

                          Comment


                            #14
                            Ok I gave it 30 minutes. So far it spent 28 of those minutes calling CAPIGetSingleControlByUser. 3312 calls so far, I have 2437 devices. Not sure if you are calling in N times per device, but I'm going to assume some multiple and let this run for a few hours and check if the number leveled off and if config starts working, it may still be in that init thread.

                            Comment


                              #15
                              Ok, at about 2 hours later the config page is working. It looks like the init thread needs to finish. The painful part was the 12370 calls to CAPIGetSingleControlByUse. is there any way those calls can be deferred until the data is needed? Perhaps only get it for enabled devices, and then get it later if a device gets enabled. I only have a dozen or so enabled devices so I suspect that would be a dramatic improvement. If not, calling to get all controls then walking the return array yourself will be much faster. Its taken HS about 518ms PER call, so about 107 minutes of time to do those 12370 calls. No idea what that call is so expensive on my system, most HS calls are much cheaper but all calls for your plugin seem high which usually means HS is spending lots of time doing something so the RCP call gets starved until HS completes what its doing. I wonder if the GetSingleControlByUse is expensively creating and then walking the list internally or something like that instead of having a cached version available.

                              Comment

                              Working...
                              X