Announcement

Collapse
No announcement yet.

Periodically get "Unable to communicate with Insteon powerline interface"

Collapse
This topic is closed.
X
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    #16
    Originally posted by NateW View Post
    Homeseer is using a 2234-222 hub, both using wired ethernet. But, there are three switches in between them. The Homeseer PC is connected to a switch, the Hub is connected to another switch, and there's a third in between those two. I will try plugging the hub into the same switch as the Homeseer PC, we'll see if that helps.

    Two things to note, though...

    Both the Hub and the PC that I'm using to type this are on the same switch, and I use remote desktop to administer the Homeseer PC from here all the time, and remote desktop works just fine.

    Again, why not just catch the exception and keep running? I mean, as opposed to catching the exception and halting the plugin until the user manually restarts it. I get that you're catching it and logging it, but that should cause the current operation to fail (no status for the dimmer), it shouldn't plug the plugin into a state where everything fails until the user intervenes.

    very time that happens, random stuff stops working around my house. Every time that happens, I just restart the plugin. Every time that happens, all is well for a few more days.

    If I had a choice between an out-of-sync device in Homeseer once every few days, versus completely nonfunctional Insteon every few days... obviously I'd rather have everything else keep working while I investigate the timeout problem.

    Network timeouts are just a fact of life. It's OK to have interactive software throw up an error when they happen, but something that runs as a service should just log the error and continue functioning as best it can. Halting isn't reasonable, especially since experience has shown that if I restart the plugin everything will work again, for days.
    the plugin does not shutdown on the error; as i mentioned it just logs the exception.

    It should continue working.
    Mark

    HS3 Pro 4.2.19.5
    Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
    Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
    Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

    Comment


      #17
      My bad. I'll try to remember this time.

      So, if that timeout is not what's causing the plugin to request a restart... what is causing it?

      Comment


        #18
        Originally posted by NateW View Post
        My bad. I'll try to remember this time.

        So, if that timeout is not what's causing the plugin to request a restart... what is causing it?
        Nate,
        if the plugin can't send 10 cmds in a row to the interface, then it will shutdown. you can extend this setting by adding the following insteon.ini setting and adjusting the value. You should see a log entry when this occurs.

        [Tuning]
        FailMargin=10

        FailMargin is the number of consecutive failed transmission attempts that occur before the Interface Stops Responding trigger is fired. 10 is the default.
        Mark

        HS3 Pro 4.2.19.5
        Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
        Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
        Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

        Comment


          #19
          @NateW

          you mentioned you have 2234-222 (but that doesn't exist as a hub model).

          do you have a Hub Pro 2243-222 (rectangular)? my understanding this is different and i don't claim to support it.

          Most of the current Hubs are 2245-222 which is square.

          please confirm model number on the bottom.
          Mark

          HS3 Pro 4.2.19.5
          Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
          Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
          Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

          Comment


            #20
            It's the 2245-222, with the square case.

            I'll try bumping up that number. Moving the hub to the other switch doesn't seem to have fixed it.

            Comment


              #21
              Originally posted by NateW View Post
              It's the 2245-222, with the square case.

              I'll try bumping up that number. Moving the hub to the other switch doesn't seem to have fixed it.
              Nate,

              typically 10 fails in a row indicates there is some external problem.

              you might consider a 'reset and reprogram' on the hub. you can do this from the plugin config page.

              i have had other users determine it was a network cable/switch port issue.

              please also consider updating to the latest beta (3.0.6.35). i made a few tweaks to the logging to avoid the detailed log messages
              Mark

              HS3 Pro 4.2.19.5
              Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
              Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
              Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

              Comment


                #22
                I'll put that in the to-do queue. Thanks for taking the time to work with me on this, I do appreciate it.

                I want to try something else first though. Since moving it to the other hub it hasn't been lasting 24 hours before needing a restart. So that has me wondering if there's a network problem. So, to investigate that I have a powershell script on the Homeseer box, running ping against the hub constantly, writing a log like this...

                5/17/2018 9:09:14 PM, 06.31, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:18 PM, 06.72, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:21 PM, 06.75, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:24 PM, 06.34, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:28 PM, 06.38, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:31 PM, 06.41, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:34 PM, 06.42, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                5/17/2018 9:09:37 PM, 06.41, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                ...so hopefully if I'm losing network connectivity, the ping log will make it clear.

                The 2nd column is the time between ping invocations, so if something is a causing the HS box to hang, that should be evident as well.

                Comment


                  #23
                  The ping log shows a few times where the time between invocations went from the usual 6.X seconds to 15-25 seconds, accompanied by 1-3 of the 4 packets sent. Something is randomly slowing the PC down, and the Homeseer problem is probably just a side-effect.

                  It definitely coincides with the timeout exceptions, but it's hard to say if it coincides with the plugin shutdowns.

                  Example:

                  5/18/2018 6:56:10 AM, 06.42, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:56:13 AM, 06.39, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:56:16 AM, 06.41, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:56:19 AM, 06.41, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:56:22 AM, 06.36, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:56:26 AM, 14.08, Packets: Sent = 4, Received = 2, Lost = 2 (50% loss),
                  5/18/2018 6:56:37 AM, 24.91, Packets: Sent = 4, Received = 2, Lost = 2 (50% loss),
                  5/18/2018 6:56:51 AM, 21.02, Packets: Sent = 4, Received = 3, Lost = 1 (25% loss),
                  5/18/2018 6:56:58 AM, 10.22, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:57:01 AM, 06.37, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:57:04 AM, 06.42, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:57:07 AM, 06.39, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 6:57:10 AM, 06.36, Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
                  5/18/2018 5:57:40 AM - ..My XML buffer begins with: 02604B42ED0333A306
                  5/18/2018 5:57:40 AM - Sending http://192.168.1.20:25105/1?XB=M=1
                  5/18/2018 6:18:14 AM - ..My XML buffer begins with: 02604B42ED0333A306
                  5/18/2018 6:18:14 AM - Sending http://192.168.1.20:25105/1?XB=M=1
                  5/18/2018 6:20:45 AM - ..My XML buffer begins with: 02604B42ED0333A306
                  5/18/2018 6:20:45 AM - Sending http://192.168.1.20:25105/1?XB=M=1
                  5/18/2018 6:56:46 AM - ***:Error in Hub.GetBuffer: The request was aborted: The operation has timed out. -- Details System.Net.WebException: The request was aborted: The operation has timed out.

                  Comment


                    #24
                    Here's the script in case anyone else is interested:

                    C:\Users\administrator\Documents>more MonitorConnectivity.ps1
                    $log="ConnectivityLog.txt"

                    Remove-Item $log

                    $lastTime = Get-Date

                    while($true)
                    {
                    $currentTime = Get-Date
                    Write-Progress -Activity "Pinging...." -Status $currentTime

                    $ping = (ping 192.168.1.20 | findstr Lost)
                    $elapsed = $currentTime.Subtract($lastTime)
                    $result = $currentTime.ToString() + ", " + $elapsed.TotalSeconds.ToString("00.00") + ", " + $ping
                    echo $result >> $log

                    $lastTime = $currentTime
                    }

                    Comment


                      #25
                      Originally posted by NateW View Post
                      The ping log shows a few times where the time between invocations went from the usual 6.X seconds to 15-25 seconds, accompanied by 1-3 of the 4 packets sent. Something is randomly slowing the PC down, and the Homeseer problem is probably just a side-effect.

                      It definitely coincides with the timeout exceptions, but it's hard to say if it coincides with the plugin shutdowns.

                      Example:
                      you should see hs log msgs if the plugin actually shuts itself down.

                      you can create a event to get notified if the hub stops responding; use the 'interface stops responding' insteon special trigger.

                      Anything further to report?
                      Mark

                      HS3 Pro 4.2.19.5
                      Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
                      Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
                      Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

                      Comment


                        #26
                        Thanks for reminding me about the HS log. I've never had an occasion to look at it until now... Here's the last couple hours of the log - apparently it shut down the plugin about 30 minutes ago.

                        Code:
                        May-22 23:09:47	 	Info	Plugin Insteon with instance: has disconnected
                        May-22 23:09:47	 	Plug-In	Shutting down Plug-In: Insteon
                        May-22 22:53:08	 	Info	System connected to MyHS Service successfully with license ID 102929.
                        May-22 22:53:08	 	Info	System connected to MyHS Service, waiting for acknowledge...
                        May-22 22:52:57	 	Warning	Error serializing myhs data: Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host.
                        May-22 22:15:01	 	Log Info	The log database is currently 3.54MB in size.
                        May-22 22:15:01	 	Log Maintenance	12 records, selected by date/time, were removed from the log database.
                        May-22 22:07:00	 	Device Control	Device: Insteon Outside Pond Lights to Off (0)
                        May-22 22:07:00	 	Event	Event Trigger "Time Of Day Events Bedtime 10:00 PM"
                        May-22 22:04:54	 	Info	System connected to MyHS Service successfully with license ID 102929.
                        May-22 22:04:54	 	Info	System connected to MyHS Service, waiting for acknowledge...
                        May-22 22:04:43	 	Warning	Error serializing myhs data: Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host.
                        May-22 21:24:44	 	Info	System connected to MyHS Service successfully with license ID 102929.
                        May-22 21:24:44	 	Info	System connected to MyHS Service, waiting for acknowledge...
                        May-22 21:24:33	 	Warning	Error serializing myhs data: Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host.
                        May-22 21:06:00	 	Energy DB Info	All energy database compacting routines completed.
                        May-22 21:06:00	 	Energy DB Info	No Records. Vacuuming database to condense.
                        May-22 21:06:00	 	Energy DB Info	Energy database compaction initiated.

                        If I filter for the word "Insteon" the log mostly looks good other than the shutdown event:


                        Code:
                        May-22 23:09:47	 	Info	Plugin Insteon with instance: has disconnected
                        May-22 23:09:47	 	Plug-In	Shutting down Plug-In: Insteon
                        May-22 22:07:00	 	Device Control	Device: Insteon Outside Pond Lights to Off (0)
                        May-22 20:54:01	 	Device Control	Device: Insteon Outside Back Patio to On (100)
                        May-22 20:54:01	 	Device Control	Device: Insteon Outside Patio Lights to On (100)
                        May-22 20:54:01	 	Device Control	Device: Insteon Outside Pond Lights to On (100)
                        May-22 20:54:01	 	Device Control	Device: Insteon Outside Generator Lights to On (100)
                        May-22 20:30:00	 	Device Control	Device: Insteon Birds Lights to Dim 25% (25)
                        May-22 20:15:00	 	Device Control	Device: Insteon Birds Lights to Dim 50% (50)
                        But if I filter by Type == Insteon, I don't see anything from the last 24 hours. There's are some signs of trouble though:

                        Code:
                        May-21 22:21:09	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 22:21:09	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 22:20:26	 	Insteon	** An error occurred in this plug-in. The details have been written to the log file - C:\Program Files (x86)\HomeSeer HS3\Config\Insteon Error Report.Log
                        May-21 22:20:26	 	Insteon	** To request help with this problem please post this log file to the forum along with a detailed description of what lead to this problem.
                        May-21 21:59:50	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:59:50	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:59:48	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:59:48	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:59:29	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:59:29	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:59:06	 	Insteon	** To request help with this problem please post this log file to the forum along with a detailed description of what lead to this problem.
                        May-21 21:59:06	 	Insteon	** An error occurred in this plug-in. The details have been written to the log file - C:\Program Files (x86)\HomeSeer HS3\Config\Insteon Error Report.Log
                        May-21 21:50:30	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:50:30	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:50:28	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:50:28	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:50:09	 	Insteon	Warning: Unable to connect to the remote server
                        May-21 21:50:09	 	Insteon	You need to set the Interface Port on the Config page, and then restart HS.
                        May-21 21:49:46	 	Insteon	** An error occurred in this plug-in. The details have been written to the log file - C:\Program Files (x86)\HomeSeer HS3\Config\Insteon Error Report.Log
                        May-21 21:49:46	 	Insteon	** To request help with this problem please post this log file to the forum along with a detailed description of what lead to this problem.
                        Does the stuff above give you any idea of what's going wrong?

                        It's worth pointing out that I haven't changed the insteon port string since forever. All I've done had to do to get it working again is just disable and re-enable the plugin when it quits working.

                        I just changed a couple more settings... These values might be unreasonably large, but if network or PC slowdowns are at the root of the problem then I'm hoping they'll work around it:

                        NumRetries=10
                        WaitTimeout=30

                        Thanks for working with me on this, I appreciate it.

                        Comment


                          #27
                          can you post the last insteon error report.log files referenced above that includes the shutdown
                          Mark

                          HS3 Pro 4.2.19.5
                          Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
                          Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
                          Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

                          Comment


                            #28
                            I'm not sure how the file names and time stamps work - which of these files is the one that the log entry was referring to?

                            Code:
                            05/17/2018  11:13 PM         2,210,513 Insteon Error Report 2018-05-18-06-56.Log
                            05/20/2018  10:34 AM         2,149,285 Insteon Error Report 2018-05-20-11-03.Log
                            05/21/2018  01:15 AM         2,101,807 Insteon Error Report 2018-05-21-07-57.Log
                            05/21/2018  06:07 PM         2,127,752 Insteon Error Report 2018-05-21-21-30.Log
                            05/21/2018  10:20 PM         2,515,296 Insteon Error Report 2018-05-22-23-26.Log
                            05/23/2018  04:33 PM         2,510,265 Insteon Error Report 2018-05-23-16-51.Log
                            05/23/2018  04:51 PM           489,802 Insteon Error Report.Log
                            I mean, is it still "Insteon Error Report.Log" that you want to see, or did the file that the log entry is referring to get renamed with a timestamp appended?

                            Comment


                              #29
                              Originally posted by NateW View Post
                              I'm not sure how the file names and time stamps work - which of these files is the one that the log entry was referring to?

                              Code:
                              05/17/2018  11:13 PM         2,210,513 Insteon Error Report 2018-05-18-06-56.Log
                              05/20/2018  10:34 AM         2,149,285 Insteon Error Report 2018-05-20-11-03.Log
                              05/21/2018  01:15 AM         2,101,807 Insteon Error Report 2018-05-21-07-57.Log
                              05/21/2018  06:07 PM         2,127,752 Insteon Error Report 2018-05-21-21-30.Log
                              05/21/2018  10:20 PM         2,515,296 Insteon Error Report 2018-05-22-23-26.Log
                              05/23/2018  04:33 PM         2,510,265 Insteon Error Report 2018-05-23-16-51.Log
                              05/23/2018  04:51 PM           489,802 Insteon Error Report.Log
                              I mean, is it still "Insteon Error Report.Log" that you want to see, or did the file that the log entry is referring to get renamed with a timestamp appended?
                              the files with a datetime stamp are archive error logs. the current log is the last one without a datetime in the filename.

                              i suspect they all have similar error message at the top of the file.

                              please post these two: Insteon Error Report 2018-05-23-16-51.Log and Insteon Error Report.Log
                              Mark

                              HS3 Pro 4.2.19.5
                              Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
                              Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
                              Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

                              Comment


                                #30
                                I'm having the same issue with the Insteon Plugin. I currently believe the Plugin issue is secondary to the hub dropping off the network, but I'm not sure what would cause the hub to disconnect nearly every day for the past several days. I discover it in this order:
                                1. a device or event doesn't trigger an Insteon device
                                2. check HS3 and find "WARNING: Please check the Interface and enter the Interface Port information on the Config page and restart HS."
                                3. Check HS3 logs to see when the issue started (seems to vary)
                                4. Ping my hub only to discover its not responding to Pings
                                5. Cycle power on Hub to recover

                                It's all been flawless for a long time, how I have to reboot the hub every day. I'm trying various network configs to see if that has anything to do with it. are there any logs available from the hub itself (i.e. SSH)?

                                Comment

                                Working...
                                X