Announcement

Collapse
No announcement yet.

Delays with version 3.0.1.124

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

    #31
    With the one log that was sent me, it appears that the issue could be related to battery devices and reporting. What happens is that the sensors send a wake up to HS, then HS checks to see if any of the sensor devices need to be polled (the polling value is set in the device properties). If so, it then tries to poll the sensor for the values. In the case of some sensors, like the Aeon motion sensor, there are up to 4 devices that need to be polled. If by chance the sensor goes back to sleep, HS will fail attempting to send to the devices and this could take a long time on a big network (30 seconds or so with the default timeout). I can re-create a delay here pretty easily with the Aeon sensor. If you have a Gen 6 sensor, you don't want to poll any of the devices as it has the ability to send updates on its own, fyi.

    To test this theory, can you go into the Z-wave config page (click on the plugin name on the plugins page) and disable polling. This will disable all polling when a device wakes up. See if the delays are still there.

    I am looking at aborting the wake up processing if the commands start to fail.
    💁‍♂️ Support & Customer Service 🙋‍♂️ Sales Questions 🛒 Shop HomeSeer Products

    Comment


      #32
      Originally posted by rjh View Post
      With the one log that was sent me, it appears that the issue could be related to battery devices and reporting. What happens is that the sensors send a wake up to HS, then HS checks to see if any of the sensor devices need to be polled (the polling value is set in the device properties). If so, it then tries to poll the sensor for the values. In the case of some sensors, like the Aeon motion sensor, there are up to 4 devices that need to be polled. If by chance the sensor goes back to sleep, HS will fail attempting to send to the devices and this could take a long time on a big network (30 seconds or so with the default timeout). I can re-create a delay here pretty easily with the Aeon sensor. If you have a Gen 6 sensor, you don't want to poll any of the devices as it has the ability to send updates on its own, fyi.

      To test this theory, can you go into the Z-wave config page (click on the plugin name on the plugins page) and disable polling. This will disable all polling when a device wakes up. See if the delays are still there.

      I am looking at aborting the wake up processing if the commands start to fail.
      Hey Rich, I wanted to let you know, I have had this box unchecked for months. I do have polling happening on the network, but I do try to limit it and disable it on anything that is instant status.

      Comment


        #33
        Originally posted by rjh View Post
        With the one log that was sent me, it appears that the issue could be related to battery devices and reporting.
        FWIW I only have one battery device, an Everspring flood sensor. It is on one of my secondary networks with only about 10 other nodes. I have 3 Aeotec multi-sensors, but they are USB powered.

        I was ready to send you logging and debug information that I captured this morning, but when I went to look at the log 3 hours later, it was all gone. No indication that HomeSeer had restarted and clear indication that the server was not restarted. I normally keep 7 days of logs and the log entries before 10:45 this morning were all gone, including the prior 7 days.

        I cleaned all that up and am sending you an email shortly.
        HS4 Pro, 4.2.19.0 Windows 10 pro, Supermicro LP Xeon

        Comment


          #34
          Noticed my first delay this morning. I can trigger my bedroom ceiling fan off in the morning from my bedside touch screen. Then when a change is detected I have an event that polls the device for it's status after a 2 second delay. initial double tap was probably me. thinking I missed the button. delay was 11 seconds.

          Jun-09 6:22:17 AM Z-Wave Device: 1st Floor Bedroom Master Bed Fan controlled by Polling Masters bedroom fan is being polled.
          Jun-09 6:22:15 AM Event Event Trigger "Polling Masters bedroom fan"
          Jun-09 6:22:15 AM Z-Wave Device: 1st Floor Bedroom Master Bed Fan Set to 0
          Jun-09 6:22:04 AM Device Control Device: 1st Floor Bedroom Master Bed Fan to Off (0) by/from: CAPI Control Handler
          Jun-09 6:22:03 AM Device Control Device: 1st Floor Bedroom Master Bed Fan to Off (0) by/from: CAPI Control Handler


          Current Date/Time: 6/9/2017 8:08:51 AM
          HomeSeer Version: HS3 Pro Edition 3.0.0.318
          Linux version: Linux HS3 4.4.0-78-generic #99-Ubuntu SMP Thu Apr 27 15:29:09 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux System Uptime: 2 Days 19 Hours 7 Minutes 24 Seconds
          Number of Devices: 335
          Number of Events: 81
          Available Threads: 400

          Enabled Plug-Ins
          3.0.2.0: AquaConnect
          2.0.35.0: BLLAN
          3.0.0.56: DSC Security
          3.0.0.68: HSTouch Server
          3.0.1.6: Kodi
          1.2.0.0: Monoprice Amp
          3.0.6280.35072: Ultra1Wire3
          3.0.0.63: weatherXML
          0.0.0.6: YAMAHA-RECEIVER
          3.0.1.126: Z-Wave
          Attached Files
          Last edited by happnatious1; June 9, 2017, 07:24 AM. Reason: add pic
          https://forums.homeseer.com/forum/de...plifier-plugin

          Comment


            #35
            Did you have debug logging enabled so I can look at the logs?

            Originally posted by happnatious1 View Post
            Noticed my first delay this morning. I can trigger my bedroom ceiling fan off in the morning from my bedside touch screen. Then when a change is detected I have an event that polls the device for it's status after a 2 second delay. initial double tap was probably me. thinking I missed the button. delay was 11 seconds.

            Jun-09 6:22:17 AM Z-Wave Device: 1st Floor Bedroom Master Bed Fan controlled by Polling Masters bedroom fan is being polled.
            Jun-09 6:22:15 AM Event Event Trigger "Polling Masters bedroom fan"
            Jun-09 6:22:15 AM Z-Wave Device: 1st Floor Bedroom Master Bed Fan Set to 0
            Jun-09 6:22:04 AM Device Control Device: 1st Floor Bedroom Master Bed Fan to Off (0) by/from: CAPI Control Handler
            Jun-09 6:22:03 AM Device Control Device: 1st Floor Bedroom Master Bed Fan to Off (0) by/from: CAPI Control Handler


            Current Date/Time: 6/9/2017 8:08:51 AM
            HomeSeer Version: HS3 Pro Edition 3.0.0.318
            Linux version: Linux HS3 4.4.0-78-generic #99-Ubuntu SMP Thu Apr 27 15:29:09 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux System Uptime: 2 Days 19 Hours 7 Minutes 24 Seconds
            Number of Devices: 335
            Number of Events: 81
            Available Threads: 400

            Enabled Plug-Ins
            3.0.2.0: AquaConnect
            2.0.35.0: BLLAN
            3.0.0.56: DSC Security
            3.0.0.68: HSTouch Server
            3.0.1.6: Kodi
            1.2.0.0: Monoprice Amp
            3.0.6280.35072: Ultra1Wire3
            3.0.0.63: weatherXML
            0.0.0.6: YAMAHA-RECEIVER
            3.0.1.126: Z-Wave
            💁‍♂️ Support & Customer Service 🙋‍♂️ Sales Questions 🛒 Shop HomeSeer Products

            Comment


              #36
              Just a quick update. Rich found some problems in the debug logs I sent him yesterday. It had to do with 2 nodes, both of which were Aeotec Smart Strips. He asked me to check and both of them were set up to poll the root node every 20 minutes and XX seconds. I have 8 of the strips. Six of them had polling enabled, I disabled the polling on all of them.

              I had disabled polling on those devices last year and had gone through all of my Z-Wave devices to check polling and disabled it on all of the devices except those that don't support instant status. I think that at one point I re-scanned the network and it added polling back, because I found it on many Cooper devices, which don't need polling and that I know I disabled it on last year.

              At Rich's suggestion, I temporarily disabled polling altogether on my system last evening. We have not seen a delay since. I restarted my system this morning at 6 and will be keeping an eye on it. Here are the log entries since I restarted:
              Code:
              Jun-09 7:53:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3909975
              Jun-09 7:50:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5634783
              Jun-09 7:47:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1726822
              Jun-09 7:44:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1882743
              Jun-09 7:41:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5003044
              Jun-09 7:38:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1248323
              Jun-09 7:35:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5320071
              Jun-09 7:32:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4064493
              Jun-09 7:29:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1481332
              Jun-09 7:26:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5009827
              Jun-09 7:23:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2399310
              Jun-09 7:20:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3288268
              Jun-09 7:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2662217
              Jun-09 7:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2535269
              Jun-09 7:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2506346
              Jun-09 7:08:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1531995
              Jun-09 7:05:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5478726
              Jun-09 7:02:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5068862
              Jun-09 6:59:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5164470
              Jun-09 6:56:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1881787
              Jun-09 6:53:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2973547
              Jun-09 6:50:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3901851
              Jun-09 6:47:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4307398
              Jun-09 6:44:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5783666
              Jun-09 6:41:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4470484
              Jun-09 6:38:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4050579
              Jun-09 6:35:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3601258
              Jun-09 6:32:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1131336
              Jun-09 6:29:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2972318
              Jun-09 6:26:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4248186
              Jun-09 6:23:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4305387
              Jun-09 6:20:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5471136
              Jun-09 6:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1239824
              Jun-09 6:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2259044
              Jun-09 6:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4287902
              Those of us who have been fighting the delays know they are very intermittent and can go hours or even a day before they surface. I have a neighbor who is also fighting the delays, he says he has had polling disabled for well over a month and still sees delays regularly.

              Time will tell, but mine has been good for 14 hours.

              I will send debug logs to Rich if or when I see them again.
              HS4 Pro, 4.2.19.0 Windows 10 pro, Supermicro LP Xeon

              Comment


                #37
                I have posted z-wave plugin 3.0.1.128, I would recommend that you load this one.

                Changes are:

                * For sure, if a battery device wakes up and for some reason goes to sleep during the process (maybe the PC was busy), the system will lock while it attempts to poll the devices. To alleviate this, the process exits on the first error and I lowered the priority on the thread so incoming requests would get serviced first. My testing shows this helps.

                * When adding a device, I removed the setting of a poll interval. As Randy noticed, if you just rescan a device, polling would get enabled. We were enabling a default polling interval on most devices. This is bad and unnecessary as most newer devices report automatically and don't need to be polled. This only affects adding or re-adding devices.
                💁‍♂️ Support & Customer Service 🙋‍♂️ Sales Questions 🛒 Shop HomeSeer Products

                Comment


                  #38
                  Rich I will update and let you know. I had delays thru the night, so I guess I need to go they the devices and see which ones are still enabled. Thanks again.

                  Comment


                    #39
                    Still no delays this morning, with Z-Wave polling disabled. .128 is installed. I will post back if I see anything. As an aside it appears my tests might be running a little quicker today than they were yesterday. My wife commented that the remotes were really fast last evening.
                    Code:
                    Jun-09 9:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2015583
                    Jun-09 9:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5629111
                    Jun-09 9:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4770354
                    Jun-09 9:08:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4774317
                    Jun-09 9:05:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1118157
                    Jun-09 9:02:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5475979
                    Jun-09 8:59:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2353695
                    Jun-09 8:56:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3739420
                    Jun-09 8:53:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4537956
                    Jun-09 8:50:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4850754
                    Jun-09 8:47:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2407595
                    Jun-09 8:44:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4225053
                    Jun-09 8:41:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5008121
                    Jun-09 8:38:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3444937
                    Jun-09 8:35:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2164926
                    Jun-09 8:32:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5033289
                    Jun-09 8:29:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3133095
                    Jun-09 8:26:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5474471
                    Jun-09 8:23:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2565173
                    Jun-09 8:20:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3130876
                    Jun-09 8:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3290009
                    Jun-09 8:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5321849
                    Jun-09 8:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1879500
                    Jun-09 8:08:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3092672
                    Jun-09 8:05:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4697042
                    Jun-09 8:02:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2820813
                    Jun-09 7:59:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2976647
                    Jun-09 7:56:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1947177
                    Jun-09 7:53:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3909975
                    Jun-09 7:50:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5634783
                    Jun-09 7:47:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1726822
                    Jun-09 7:44:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1882743
                    Jun-09 7:41:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5003044
                    Jun-09 7:38:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1248323
                    Jun-09 7:35:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5320071
                    Jun-09 7:32:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4064493
                    Jun-09 7:29:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1481332
                    Jun-09 7:26:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5009827
                    Jun-09 7:23:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2399310
                    Jun-09 7:20:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3288268
                    Jun-09 7:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2662217
                    Jun-09 7:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2535269
                    Jun-09 7:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2506346
                    Jun-09 7:08:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1531995
                    Jun-09 7:05:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5478726
                    Jun-09 7:02:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5068862
                    Jun-09 6:59:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5164470
                    Jun-09 6:56:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1881787
                    Jun-09 6:53:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2973547
                    Jun-09 6:50:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3901851
                    Jun-09 6:47:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4307398
                    Jun-09 6:44:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5783666
                    Jun-09 6:41:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4470484
                    Jun-09 6:38:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4050579
                    Jun-09 6:35:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.3601258
                    Jun-09 6:32:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1131336
                    Jun-09 6:29:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2972318
                    Jun-09 6:26:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4248186
                    Jun-09 6:23:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4305387
                    Jun-09 6:20:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.5471136
                    Jun-09 6:17:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.1239824
                    Jun-09 6:14:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.2259044
                    Jun-09 6:11:11 AM	 	Delay	Z-Wave delay test completion time 00:00:00.4287902
                    HS4 Pro, 4.2.19.0 Windows 10 pro, Supermicro LP Xeon

                    Comment


                      #40
                      Rich as an FYI, I just updated to 128 and found that my zwave confit page changed. Disabled my debit logging (no biggie and kinda expected), but it rechecked my polling box.

                      Comment


                        #41
                        Originally posted by waynehead99 View Post
                        Rich as an FYI, I just updated to 128 and found that my zwave confit page changed. Disabled my debit logging (no biggie and kinda expected), but it rechecked my polling box.
                        Mine remained unchecked when I went from .126 to .128.
                        HS4 Pro, 4.2.19.0 Windows 10 pro, Supermicro LP Xeon

                        Comment


                          #42
                          Originally posted by rjh View Post
                          Did you have debug logging enabled so I can look at the logs?
                          I thought you said don't enable if on linux.
                          https://forums.homeseer.com/forum/de...plifier-plugin

                          Comment


                            #43
                            I still have issues with delays on the Z-wave network.
                            1.124 was horrible.
                            1.126 was a little better.
                            1.128 was about the same as .126.

                            Anybody else see this?
                            HSPro 3.0.0.458, Z-NET with Z-wave plugin 3.0.1.190, RFXCOM + 2x RFXtrx433E, HSTouch, Squeezebox plugin, iTach IP/WF2IR & GC-100-6 with UltraGCIR, BLDenon, NetcamStudio, Jon00s Webpage builder, Harmony Hub plugin, SCSIP (with FreePBX), Arduino plugin, IFTTT, Pushalot plugin, Device History plugin.
                            Running on Windows 10 (64) virtualized
                            on ESXi (Fujitsu Primergy TX150 S8).
                            WinSeer (for Win10) - TextSeer - FitbitSeer - HSPI_MoskusSample

                            Are you Norwegian (or Scandinavian) and getting started with HomeSeer? Read the "HomeSeer School"!

                            Comment


                              #44
                              Originally posted by Moskus View Post
                              I still have issues with delays on the Z-wave network.
                              1.124 was horrible.
                              1.126 was a little better.
                              1.128 was about the same as .126.

                              Anybody else see this?
                              .126 cleaned up all my delay issues 100% on all four networks. I haven't tried .128, but I am reluctant to make any changes now in the plug in now that I finally got back to normal.

                              Comment


                                #45
                                1.110 was "perfect" in regards to delays.
                                1.124 gave horrible delays.
                                1.126 was better, but still not as good as .110
                                1.128 the same as 1.126.

                                Extremaly annoying!
                                HSPro 3.0.0.458, Z-NET with Z-wave plugin 3.0.1.190, RFXCOM + 2x RFXtrx433E, HSTouch, Squeezebox plugin, iTach IP/WF2IR & GC-100-6 with UltraGCIR, BLDenon, NetcamStudio, Jon00s Webpage builder, Harmony Hub plugin, SCSIP (with FreePBX), Arduino plugin, IFTTT, Pushalot plugin, Device History plugin.
                                Running on Windows 10 (64) virtualized
                                on ESXi (Fujitsu Primergy TX150 S8).
                                WinSeer (for Win10) - TextSeer - FitbitSeer - HSPI_MoskusSample

                                Are you Norwegian (or Scandinavian) and getting started with HomeSeer? Read the "HomeSeer School"!

                                Comment

                                Working...
                                X