Announcement

Collapse
No announcement yet.

GoControl - Program Not Functioning

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

  • #16
    I tried a different approach to deal with the timing. I think you will have success. Let me know. http://mcsSprinklers.com/mcsSprinkle...19_4_3_HS3.zip

    In the mcsSprinklers RunLog page you should see EXTERNAL ON and EXTERNAL OFF spanning the time the valve is controlled. In the HS log you will see something like the following for the two Area 1 zones running at 1 minute each
    May-10 9:52:50 AM Device Control Device: Node 4 Z-Wave Irrigation Valve to Off (0) by/from: CAPI Control Handler
    May-10 9:51:50 AM Device Control Device: Node 4 Z-Wave Irrigation Valve to Valve 2 On for 5 min (1282) by/from: CAPI Control Handler
    May-10 9:51:50 AM Device Control Device: Node 4 Z-Wave Irrigation Valve to Off (0) by/from: CAPI Control Handler
    May-10 9:50:49 AM Device Control Device: Node 4 Z-Wave Irrigation Valve to Valve 1 On for 5 min (1281) by/from: CAPI Control Handler

    Comment


    • #17
      Thanks Michael. I'll try it out and report back. It might be a couple of days since I promised my wife to focus on some higher priority issues (according to her!)


      Thanks,
      Craig

      Comment


      • #18
        I had a brief amount of time to run the new version but I think there is still a timing problem. Using my same zone/area layout with a 1 minute time set to each zone, here is what I got when running the program manually:

        Area1 Zone 1: 07:49:56 Started and ran. Shut off at 07:50:58 (1 minute - 2 seconds)
        Area1 Zone 2: 07:50:58 Attempted to start but didn't.
        Area2 Zone 3: 07:50:58 Started and ran. Shut off at 07:52:00 (1 minute - 2 seconds)
        Area3 Zone 4: 07:52:00 Attempted to start but didn't.
        Area2 Zone 3: 07:52:00 Started and ran. Shut off at 07:53:00 (1 minute exactly)

        I looked at the debug file and saw some inconsistencies with the "Commanding" and "CommonExecX10" entries. In each instance where the zone ran correctly, there was an "ON" (status 2) AND an "OFF" (status 3) entry. In the instances where the Zone didn't run (Zone 2 and Zone 4 in my case), there was only an "ON" (status 2) entry without any corresponding "OFF" (status 3). This looks like similar behavior that you observed in post #13.

        I double-checked to make sure I have the correct version installed. While the plug-in management page indicates MCSSPRINKLERSP v2.19.4.2, when I click on property details of the HSPI_MCSSPRINKLERS.exe file it shows as v2.19.4.3 So I think I have the right one running.

        Do you think there is any merit in me erasing my existing mcsSprinklers configuration and start from scratch? It wouldn't be very difficult as my layout is fairly small and I haven't setup any complex instructions.

        Click image for larger version

Name:	19-05-11-07-49-56 HS3 Log.JPG
Views:	35
Size:	46.5 KB
ID:	1304165
        Attached Files

        Comment


        • #19
          Don't start over. The problem is not with your configuration.

          Next step will be to simulate an acknowledge such as exists with many of the interfaces. When the acknowledge is not received then mcsSprinklers will retry the command up to 4 times. The original Rain8 X10, Rain8 Wireless, Rpi and all HS virtual devices (and GoControl) are implemented as if the command given was accepted. The others Rain8 X10-2, Rain8 UPB, Etherrain, xAP and MQTT devices get an acknowledge which enables the ability to detect and manage failures.

          Comment


          • #20
            Got it. I'll sit tight.

            Comment


            • #21
              I started down the emulation route and found it was too complex to marry it with the other acknowledge mechanism with the other controllers. Instead I did a dedicated command/acknowledge for the GoControl. I expect this to work for everybody, but just in case I added more debug around the handshake mechanism.

              An example below for a program of two zones running for two minutes each. It starts with the command shown on the first line. The second line is the HS Event callback showing the GoControl device recognized (as device 1337) and that an ON(2) is expected for R1. It also shows that a 5 minute program (1280+1) was given to the Zwave device for valve 1. The third line is also in the HS Event callback showing where mcsSprinklers recognizes the command as being Zone R1 ON (2). If these did not match then the acknowledge would not have been given and a command retry given in 2 seconds. The retry would have been in the debug too. In the mcsSprinklers Run Log page a normal Command ON and Command OFF sequence should be observed. No EXTERNAL status in the log.

              Code:
              5/14/2019 10:07:01 AM 636934252214337992 | mcsSprinklers Debug | GoControl Command R1  to ON for 2
              5/14/2019 10:07:01 AM 636934252215638067 | mcsSprinklers Debug | GoControl Parms(2)/Status=1281, Parms(4)/Ref=1337, AcknowledgeExpected=2, ControlDevice=R1
              5/14/2019 10:07:01 AM 636934252215678069 | mcsSprinklers Debug | Commanding R1 to 2, is an Ailias=False,LastChange=5/14/2019 10:07:01 AM, Status=2
              
              5/14/2019 10:09:01 AM 636934253410036382 | mcsSprinklers Debug | GoControl Command R1  to OFF for 0
              5/14/2019 10:09:01 AM 636934253411406461 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=1337, AcknowledgeExpected=3, ControlDevice=R1
              5/14/2019 10:09:01 AM 636934253411446463 | mcsSprinklers Debug | Commanding R1 to 3, is an Ailias=False,LastChange=5/14/2019 10:09:00 AM, Status=3
              
              5/14/2019 10:09:01 AM 636934253416776768 | mcsSprinklers Debug | GoControl Command R2  to ON for 2
              5/14/2019 10:09:01 AM 636934253418256853 | mcsSprinklers Debug | GoControl Parms(2)/Status=1282, Parms(4)/Ref=1337, AcknowledgeExpected=2, ControlDevice=R2
              5/14/2019 10:09:01 AM 636934253418296855 | mcsSprinklers Debug | Commanding R2 to 2, is an Ailias=False,LastChange=5/14/2019 10:09:01 AM, Status=2
              It is at http://mcsSprinklers/mcsSprinklersP_2_19_4_4_HS3.zip Please confirm and I will put it in the updater.

              Comment


              • #22
                Thanks Michael. I'll give it go today and report back.

                Craig

                Comment


                • #23
                  Hi Michael, I ran the update and did 2 hours of testing. Definitely good progress but there are a few things I’m seeing.
                  1. The program doesn’t seem to like a 1 minute duration on the zones.I was not able to get consistent behavior in any of the runs where I had a 1 minute duration.When I switched to a 2 minute duration, I was able to get repeatable results.
                  2. In all instances of running the program, regardless of the duration, the Time Remaining that showed up in the Zone Status and General Status was exactly 1 minute longer than the program run time. For example, if I had a 1 minute duration, it would say it had 2 minutes remaining when the zone started. When I had a 2 minute duration, it would say it had 3 minutes remaining. The zone would shut off when it was supposed to but the time remaining status seemed to be incorrect. Perhaps there is some relationship between this and why it doesn’t seem to like 1 minute duration ?
                  3. In all instances my R3 zone ran again after all zones had completed.Then when I looked at the Run List, it indicated that R3 would not be run in the next program run (which would typically be tomorrow in my setup). But it would run when I manually started all zones from the Web Control.
                  4. I use Firefox as my browser. The Zone Status page isn’t automatically updating for me as the zones run. Perhaps a browser setting on my end. But when I manually try to refresh the page, it seems to want to send another Web Control command to Manually Start the zones. This could explain some of the strange behavior and extra Manual Start from Web Control entries in the DEBUG log.

                  09:51:20 - When I re-enabled the plugin it automatically began the program for those zones that were to have been run earlier today but didn’t (I’m assuming because the plugin had been disabled and it was trying to catch up). Each Zone was set for 1 minute.
                  5/16/2019 9:51:20 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 9:52:21 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 9:52:21 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 9:53:21 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 9:53:21 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 9:54:21 AM A2:R3 mcsSprinklers Drip OFF
                  This looked great and what I would have expected! So far so good.

                  09:55:47 – I then started all zones manually from the Zone Status page. All zones ran for the 1 minute program, except that zone 3 ran again briefly after the 4 zones had already run.
                  5/16/2019 9:55:47 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 9:56:48 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 9:56:48 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 9:57:49 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 9:57:49 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 9:58:49 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 9:58:49 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 9:59:49 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 10:00:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:00:19 AM A2:R3 mcsSprinklers Drip OFF
                  10:00:21 – I stated all zones manually again to see if I could replicate this behavior. Similar behavior except now an External OFF for R1. R3 ran again after the other zones had run their program.
                  5/16/2019 10:00:21 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 10:00:24 AM A1:R1 mcsSprinklers Lawn 1 External OFF
                  5/16/2019 10:00:25 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 10:01:25 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 10:01:25 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:02:26 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 10:02:26 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 10:03:26 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 10:04:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:05:00 AM A2:R3 mcsSprinklers Drip OFF
                  10:05:09 – Manual start. No EXTERNAL OFF but again R3 runs again after program is completed.
                  5/16/2019 10:05:09 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 10:06:10 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 10:06:10 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 10:07:10 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 10:07:10 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:08:11 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 10:08:11 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 10:09:12 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 10:10:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:11:00 AM A2:R3 mcsSprinklers Drip OFF
                  10:20:55 – Manual start and ran perfectly. No changes were made.
                  5/16/2019 10:20:55 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 10:21:56 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 10:21:56 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 10:22:57 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 10:22:57 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:23:58 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 10:23:58 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 10:24:59 AM A3:R4 mcsSprinklers Trees OFF

                  10:25:50 – Manual start after changing program times to 2 minutes (instead of 1). According to the DEBUG file, it looks like Manual start was hit multiple times, but I don’t think I did. At any rate, the behavior was not as expected. Note that R1 was on for 5 minutes but should have been 2. The only thing that was consistent was that R3 ran again after the other zones completed.
                  5/16/2019 10:25:50 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 10:30:47 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 10:30:47 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 10:32:48 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 10:32:48 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:34:48 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 10:34:48 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 10:36:49 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 10:37:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 10:39:00 AM A2:R3 mcsSprinklers Drip OFF

                  11:06:09 – Ran again to try and replicate the behavior. Again the DEBUG log shows that Manual Start was entered again but wasn’t. Although I think I have an idea of what is causing it. I’m using Firefox as my browser and sometimes when I try to manually refresh the Zone status page, it asks if I want to ReSend previously sent data… to which I respond “ReSend”. This may have resulted in a resending of the Manual Start command even though I didn’t expressly request it. Again R3 ran again after all other zones ran.
                  5/16/2019 11:06:09 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 11:08:10 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 11:08:10 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 11:10:53 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 11:10:53 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 11:12:53 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 11:12:53 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:14:53 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 11:14:53 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 11:16:53 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 11:17:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:19:00 AM A2:R3 mcsSprinklers Drip OFF
                  11:27:59 – Ran the program manually twice in a row and didn’t attempt to manually refresh the Zone Status page. Behavior repeated exactly the same with R3 running again after all zones had run. Also noted that R3 was removed from the next program Run List.
                  5/16/2019 11:27:59 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 11:30:00 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 11:30:00 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 11:32:00 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 11:32:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:34:00 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 11:34:00 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 11:36:00 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 11:37:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:39:00 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 11:41:01 AM A1:R1 mcsSprinklers Lawn 1 ON
                  5/16/2019 11:43:02 AM A1:R1 mcsSprinklers Lawn 1 OFF
                  5/16/2019 11:43:02 AM A1:R2 mcsSprinklers Lawn 2 ON
                  5/16/2019 11:45:02 AM A1:R2 mcsSprinklers Lawn 2 OFF
                  5/16/2019 11:45:02 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:47:03 AM A2:R3 mcsSprinklers Drip OFF
                  5/16/2019 11:47:03 AM A3:R4 mcsSprinklers Trees ON
                  5/16/2019 11:49:04 AM A3:R4 mcsSprinklers Trees OFF
                  5/16/2019 11:50:00 AM A2:R3 mcsSprinklers Drip ON
                  5/16/2019 11:52:00 AM A2:R3 mcsSprinklers Drip OFF
                  Attached Files

                  Comment


                  • #24
                    I found an issue with respect to the R3 zone running and addressed it. I did not see display time vs. run time issues. It may be related to the second problem which is the same problem we started with. I had provided a window of 2 seconds for HS to respond to the command given. Your log shows it took 5 seconds for the 10:00:19 command to turn R3 off. I bumped up the window to 15 seconds with 2.19.4.5 at http://mcsSprinklers/mcsSprinklersP_2_19_4_5_HS3.zip . Same routine for evaluation.

                    Code:
                    Sent R3 OFF to HS/GoControl but no event callback received.  Retry of command and proceeded without waiting for event callback 
                    5/16/2019 10:00:19 AM 636935976197315130 | mcsSprinklers Debug | GoControl Command R3  to OFF for 0
                    5/16/2019 10:00:21 AM 636935976219155169 | mcsSprinklers Debug | GoControl Command Retry R3  to OFF for 0
                    
                    R1 commanded ON, but again no event callback from HS/GoControl
                    5/16/2019 10:00:21 AM 636935976219935170 | mcsSprinklers Debug | GoControl Command R1  to ON for 2
                    5/16/2019 10:00:24 AM 636935976241931209 | mcsSprinklers Debug | GoControl Command Retry R1  to ON for 2
                    
                    HS Event callback that is reporting OFF, but by this time mcsSprinklers had moved on to R1 ON.  This is a 5 second delay from OFF command to OFF feedback.  This yielded the EXTERNAL OFF
                    5/16/2019 10:00:24 AM 636935976248951221 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R1

                    Comment


                    • #25
                      This version solved the R3 problem. I tested using both Manual Starts from the Zone Status Page and also setting timers in the Program Setup page. The program performed exactly as expected using times and duration setup in the Program Setup. Very consistent results. Even the run times were correct. But when starting zones manually via the Zone Setup page, I was still seeing run time status issues as I mentioned before although the zones ran as expected. Attached is a screen shot of a manual run with a 2 minute run time on all the zones. On the manual runs form the Zone Status page, I noted two entries 17 seconds apart where the the first zone was commanded to turn on. This didn't happen when zones were turned on via the programmed start times. These didn't seem to affect the performance of the program, rather they just seemed to be anomalies.

                      Here is the HomeSeer log typical of the manual runs:
                      May-17 1:08:13 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Off (0) by/from: CAPI Control Handler
                      May-17 1:06:13 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Valve 4 On for 5 min (1284) by/from: CAPI Control Handler
                      May-17 1:06:13 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Off (0) by/from: CAPI Control Handler
                      May-17 1:04:12 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Valve 3 On for 5 min (1283) by/from: CAPI Control Handler
                      May-17 1:04:12 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Off (0) by/from: CAPI Control Handler
                      May-17 1:02:11 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Valve 2 On for 5 min (1282) by/from: CAPI Control Handler
                      May-17 1:02:11 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Off (0) by/from: CAPI Control Handler
                      May-17 1:00:27 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Valve 1 On for 5 min (1281) by/from: CAPI Control Handler
                      May-17 1:00:10 PM Device Control Device: Sprinklers Backyard Irrigation Valve to Valve 1 On for 5 min (1281) by/from: CAPI Control Handler
                      Attached is the DEBUG log.

                      Attached Files

                      Comment


                      • #26
                        I see what you mean about the one minute bias. I was always looking in the auto mode for display. I did not see an issue on the General Status page for duration in manual mode. I addressed it in http://mcsSprinklers.com/mcsSprinkle...19_4_6_HS3.zip. I will also submit it to updater.

                        I also forgot to mention that the Other Page, Browser Display Options has a refresh interval setting that applies to the Zone Status page. The touch pages should always refresh every 15 seconds independent of this setting. The other pages do not refresh automatically.

                        I observed more timeouts than I expect in your last log. With the additional delay it looks to have stabilized the handshake, but kind of bothersome. I also notice that the acknowledge, when a command was resent, always came as a page refresh was happening as I could see the links at the top of the page being produced in the log. It raises the question if the acknowledge would ever come if a browser page was not being refreshed or new one built. No acknowledge is not a problem, but an acknowledge of the first that comes after a different zone has been commanded is a problem as we saw with all your prior attempts.

                        Code:
                        5/17/2019 1:00:10 PM 636936948109462414 | mcsSprinklers Debug | GoControl Command R1  to ON for 3
                        5/17/2019 1:00:27 PM 636936948273418702 | mcsSprinklers Debug | GoControl Command Retry R1  to ON for 3
                        5/17/2019 1:00:27 PM 636936948279658713 | mcsSprinklers Debug | GoControl Parms(2)/Status=1281, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R1
                        
                        5/17/2019 1:02:11 PM 636936949311912526 | mcsSprinklers Debug | GoControl Command R1  to OFF for 0
                        5/17/2019 1:02:11 PM 636936949313160528 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R1
                        
                        5/17/2019 1:02:11 PM 636936949315032532 | mcsSprinklers Debug | GoControl Command R2  to ON for 3
                        5/17/2019 1:02:11 PM 636936949316280534 | mcsSprinklers Debug | GoControl Parms(2)/Status=1282, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R2
                        
                        5/17/2019 1:04:12 PM 636936950522006652 | mcsSprinklers Debug | GoControl Command R2  to OFF for 0
                        5/17/2019 1:04:12 PM 636936950523410654 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R2
                        
                        5/17/2019 1:04:12 PM 636936950525126657 | mcsSprinklers Debug | GoControl Command R3  to ON for 3
                        5/17/2019 1:04:12 PM 636936950526530660 | mcsSprinklers Debug | GoControl Parms(2)/Status=1283, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R3
                        
                        5/17/2019 1:06:13 PM 636936951731788777 | mcsSprinklers Debug | GoControl Command R3  to OFF for 0
                        5/17/2019 1:06:13 PM 636936951733192779 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R3
                        
                        5/17/2019 1:06:13 PM 636936951734752782 | mcsSprinklers Debug | GoControl Command R4  to ON for 3
                        5/17/2019 1:06:13 PM 636936951736156784 | mcsSprinklers Debug | GoControl Parms(2)/Status=1284, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R4
                        
                        5/17/2019 1:08:13 PM 636936952931898884 | mcsSprinklers Debug | GoControl Command R4  to OFF for 0
                        5/17/2019 1:08:13 PM 636936952933146887 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R4
                        
                        5/17/2019 1:09:02 PM 636936953428603757 | mcsSprinklers Debug | GoControl Command R1  to ON for 3
                        5/17/2019 1:09:19 PM 636936953592404045 | mcsSprinklers Debug | GoControl Command Retry R1  to ON for 3
                        5/17/2019 1:09:19 PM 636936953599112056 | mcsSprinklers Debug | GoControl Parms(2)/Status=1281, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R1
                        
                        5/17/2019 1:11:03 PM 636936954631989870 | mcsSprinklers Debug | GoControl Command R1  to OFF for 0
                        5/17/2019 1:11:03 PM 636936954633237873 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R1
                        
                        5/17/2019 1:11:03 PM 636936954634953876 | mcsSprinklers Debug | GoControl Command R2  to ON for 3
                        5/17/2019 1:11:03 PM 636936954636045878 | mcsSprinklers Debug | GoControl Parms(2)/Status=1282, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R2
                        
                        5/17/2019 1:13:03 PM 636936955831943978 | mcsSprinklers Debug | GoControl Command R2  to OFF for 0
                        5/17/2019 1:13:03 PM 636936955833347981 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R2
                        
                        5/17/2019 1:13:03 PM 636936955835063984 | mcsSprinklers Debug | GoControl Command R3  to ON for 3
                        5/17/2019 1:13:03 PM 636936955836311986 | mcsSprinklers Debug | GoControl Parms(2)/Status=1283, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R3
                        
                        5/17/2019 1:15:03 PM 636936957031742085 | mcsSprinklers Debug | GoControl Command R3  to OFF for 0
                        5/17/2019 1:15:03 PM 636936957033302088 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R3
                        
                        5/17/2019 1:15:03 PM 636936957035018091 | mcsSprinklers Debug | GoControl Command R4  to ON for 3
                        5/17/2019 1:15:03 PM 636936957036422094 | mcsSprinklers Debug | GoControl Parms(2)/Status=1284, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R4
                        
                        5/17/2019 1:17:04 PM 636936958241836211 | mcsSprinklers Debug | GoControl Command R4  to OFF for 0
                        5/17/2019 1:17:04 PM 636936958243240213 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R4
                        
                        5/17/2019 1:17:35 PM 636936958553836759 | mcsSprinklers Debug | GoControl Command R4  to ON for 2
                        5/17/2019 1:17:51 PM 636936958717637047 | mcsSprinklers Debug | GoControl Command Retry R4  to ON for 2
                        5/17/2019 1:17:52 PM 636936958723721057 | mcsSprinklers Debug | GoControl Parms(2)/Status=1284, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R4
                        
                        5/17/2019 1:18:36 PM 636936959161925827 | mcsSprinklers Debug | GoControl Command R4  to OFF for 0
                        5/17/2019 1:18:36 PM 636936959163329829 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R4
                        
                        5/17/2019 1:19:23 PM 636936959638506664 | mcsSprinklers Debug | GoControl Command R4  to ON for 3
                        5/17/2019 1:19:40 PM 636936959802306952 | mcsSprinklers Debug | GoControl Command Retry R4  to ON for 3
                        5/17/2019 1:19:40 PM 636936959808234962 | mcsSprinklers Debug | GoControl Parms(2)/Status=1284, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R4

                        Comment


                        • #27
                          Thanks Michael, I'm running this version now without water actually flowing to the valves. I've got lots of rain lately so it makes it easier to test without compromising the landscape. I'll let you know what I see.

                          Comment


                          • #28
                            Hi Michael, I updated the plugin and changed the browser refresh time to 15 seconds but the page does not refresh unless I force it. And I'm still getting that 17 second delay when trying to start the program manually from the Zone Status page. When trying to run the zones on an automatic schedule, I'm also seeing an issue that I've seen a long time ago where the Project Start times keep advancing by 1 minute and never actually starting. I seem to recall it might have had something to do with an incomplete interview... so I went back through it. No change.

                            At this point I started the zones manually and we see the delay as we did before.
                            Line 20153: 5/19/2019 8:14:17 AM 636938504574980024 | mcsSprinklers Debug | GoControl Command R1 to ON for 6
                            Line 20155: 5/19/2019 8:14:33 AM 636938504738936312 | mcsSprinklers Debug | GoControl Command Retry R1 to ON for 6
                            Line 20327: 5/19/2019 8:14:34 AM 636938504745488323 | mcsSprinklers Debug | GoControl Parms(2)/Status=2561, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R1

                            Everything else ran fine. What's odd is it says "for 6" although the program time was 5 mins. Is this to deal with the 1 minute bias?
                            Line 20903: 5/19/2019 8:19:18 AM 636938507581885305 | mcsSprinklers Debug | GoControl Command R1 to OFF for 0
                            Line 20904: 5/19/2019 8:19:18 AM 636938507583289308 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R1

                            Line 20940: 5/19/2019 8:19:18 AM 636938507585161311 | mcsSprinklers Debug | GoControl Command R2 to ON for 6
                            Line 20941: 5/19/2019 8:19:18 AM 636938507586253313 | mcsSprinklers Debug | GoControl Parms(2)/Status=2562, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R2

                            Line 21590: 5/19/2019 8:24:18 AM 636938510582082575 | mcsSprinklers Debug | GoControl Command R2 to OFF for 0
                            Line 21591: 5/19/2019 8:24:18 AM 636938510583330577 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R2

                            Line 21627: 5/19/2019 8:24:18 AM 636938510585202580 | mcsSprinklers Debug | GoControl Command R3 to ON for 6
                            Line 21628: 5/19/2019 8:24:18 AM 636938510586294582 | mcsSprinklers Debug | GoControl Parms(2)/Status=2563, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R3

                            Line 22280: 5/19/2019 8:29:18 AM 636938513582123844 | mcsSprinklers Debug | GoControl Command R3 to OFF for 0
                            Line 22281: 5/19/2019 8:29:18 AM 636938513583371846 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R3

                            Line 22317: 5/19/2019 8:29:18 AM 636938513585087849 | mcsSprinklers Debug | GoControl Command R4 to ON for 61
                            Line 22318: 5/19/2019 8:29:18 AM 636938513586335851 | mcsSprinklers Debug | GoControl Parms(2)/Status=7684, Parms(4)/Ref=937, AcknowledgeExpected=2, ControlDevice=R4

                            I decided to stop the program manually from the zone status page rather than wait for the 60 minutes I had programmed. Again a 17 second delay in getting acknowledgement
                            Line 22972: 5/19/2019 8:34:58 AM 636938516986361823 | mcsSprinklers Debug | GoControl Command R4 to OFF for 0
                            Line 22978: 5/19/2019 8:35:15 AM 636938517150318111 | mcsSprinklers Debug | GoControl Command Retry R4 to OFF for 0
                            Line 23084: 5/19/2019 8:35:15 AM 636938517154062118 | mcsSprinklers Debug | GoControl Parms(2)/Status=0, Parms(4)/Ref=937, AcknowledgeExpected=3, ControlDevice=R4
                            Attached Files

                            Comment


                            • #29
                              According to the debug log the walking delay in starting was due to a rain inhibit for two of the areas. I did not look any further for this as it is reasonable that mcsSprinklers will never know when the rain inhibit will be lifted. Looking at the General Status page one can see the inhibits that are outstanding.

                              The refresh is just a parameter given to the browser to have it reload page at some periodic interval. The issue is that the header where this is communicated is generated by HS. I believe with HS3 the philosophy is to use AJAX to update specific fields rather than an entire page so I do not think this setting has any value. HS3 actually builds the header itself so it can put all the stuff at the top for its menus and javascript.

                              The one minute bias is for the Etherrain. If I want 5 minutes then I tell Etherrain to run for 6. At 5 I will send OFF command,, but if for some reason the OFF does not happen the valve is protected. Same philosophy used with Rain8, but in that case the Rain8 has a fixed timeout protection. For the GoControl it is the next highest step in the number of minutes that can be programmed.

                              The good news out of this is that I ran down the issue with running the GoControl manually and have a good solution in http://mcsSprinklers.com/mcsSprinkle...19_4_7_HS3.zip.
                              When HS was servicing a browser request it was waiting for the plugin to return before it did things like firing event callbacks. Since the intent was to immediately start the irrigation cycle with manual control, mcsSprinklers did not return immediately, but started the cycle which included sending command to GoControl. With the handshake logic it would wait for the HS Event which never came. I resolved this issue by starting the irrigation cycle in a new thread and immediately return to HS from the browser response thread.

                              Uploading has been problematic this weekend. I will keep trying to get the zip uploaded. I will also try to get it submitted to updater.

                              Comment


                              • #30
                                Makes sense. I downloaded the zip and have 19_4_7 running now. Manual starts from Zone Status started within 1 second and I don't see any retry in the DEBUG log, so that seems to be resolved. I did see where I had two inhibits based on rain and I removed those. We'll see what happens tomorrow morning when the zones are set to run. Looking good so far and thanks for all your work!

                                Craig

                                Comment

                                Working...
                                X