Foster Systems Roof Not Working With Scheduler 3.5

[Todd Benko]

I just moved up to Scheduler 3.5.1 and am now getting scheduler dead conditions. I believe the issue is somehow related to the rate at which the roll off roof controller is polled.

The roof is issued a open command. The readback will be closed then go opening, and then back to closed then the roof controller relay finally clicks and starts to open and then roof condition is reporting opening again. This is with the Foster systems roll off roof controller. I think the query is happening too quickly and the sequence from the controller is confusing scheduler. Nothing has changed with the hardware and everything was working fine with Scheduler 3.4.

Here is the short log results when the error occurs on evening startup.

Todd



Log opened at Fri, Apr 06 2012 19:41:40 UTC (actual time)Current log level is VerboseScheduler version 3.5.107-Apr-2012 02:14:13.8: ++ Observatory Startup ++07-Apr-2012 02:14:13.9: Start ACP Sequencer's StartupObs script07-Apr-2012 02:15:38.6: Open the observatory dome/roof07-Apr-2012 02:15:48.6: **Dome closed while opening. Assuming weather closure.07-Apr-2012 02:15:48.7: **EXCEPTION IN SCHEDULER:07-Apr-2012 02:15:48.7: **Dome failed to open for reason other than hardware weather closure07-Apr-2012 02:15:48.8: Traceback: at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome) at DC3.Scheduler.Engine.Run()07-Apr-2012 02:15:49.0: Run statistics:07-Apr-2012 02:15:49.0: Observations: 14807-Apr-2012 02:15:49.0: Considered: 11007-Apr-2012 02:15:49.0: Completed: 7307-Apr-2012 02:15:49.0: Skipped: 007-Apr-2012 02:15:49.0: Never Eligible: 3807-Apr-2012 02:15:49.0: Failed: 3707-Apr-2012 02:15:49.0: Shutter-Open efficiency: 0.00-Apr-2012 02:15:49.0: Overall Efficiency: 0.00-Apr-2012 02:15:49.0: Release ACP sequencerLog closed at Sat, Apr 07 2012 02:15:50 UTC (actual time)

[Bob Denny]

Todd --

OK, yes the weather and dome handling was changed in a big way with 3.5. The objective was to allow the weather to remain connected no matter what, until shutdown/dawn flats time.

The readback will be closed then go opening, and then back to closed then the roof controller relay finally clicks and starts to open and then roof condition is reporting opening again. This is with the Foster systems roll off roof controller. I think the query is happening too quickly and the sequence from the controller is confusing scheduler. Nothing has changed with the hardware and everything was working fine with Scheduler 3.4.

That's what's doing it. The polling rate is a lazy once every 15 seconds. The new logic is designed to monitor dome/roof operations and handle the situation where a hardware weather closure happens while it is in the process of opening up. That situation would like Scheduler before. As you might imagine, I never expected the "shutter" status to switch back and forth like that. It's the switch from opening back to closed that's doing it. The exception is the result of the apparent problems opening. How ugly. I held 3.5 in beta for so long... Now that's several dome and weather related things, one mine (dawn cal frames with bad weather) and the rest due to quirks in weather and dome operation that I couldn't have anticipated. Dang it. Here's the opening code if you're curious:

        //
        // Dome shutter control. Harmless if no dome/roof or already open. Throws on dome errors (typ.)
        // WE DO NOT HAVE WEATHER KNOWLEDGE!
        //
        // NOTE: This is an unclean interface. It returns false if the dome wasn't opened because
        //       it was found to be closing or remained closed after being told to open. The 
        //       assumption is that an external hardware closure is in effect.
        //
        public bool OpenDome()
        {
            ACP.Dome Dome = m_ACPUtil.Dome;                             // Shortcut
            if (!Dome.Available || !Dome.CanSetShutter)
                return true;
            if (!WeatherSafe)                                           // Just went unsafe
                return false;
            
            if (Dome.Available && Dome.ShutterStatus != ACP.ShutterState.shutterOpen)
            {
                switch (Dome.ShutterStatus)
                {
                    case ACP.ShutterState.shutterClosed:
                        Logger.Log("Open the observatory dome/roof", LogLevel.Verbose);
                        //
                        // TODO What happens here if an external hardware closure 
                        // is in effect? It is undefined. If an exception is raised, 
                        // what do we do? I elected to just let the error fly and
                        // kill the dispatcher. 
                        //
                        Dome.OpenShutter();
                        //
                        // HACK! My tester has MaxDome, and it can take "some time" before it
                        // reports that it is Opening. Immediately after returning from this, 
                        // it says it's still Closed and triggers the "assuming weather closure"
                        // case in the second switch statement below.
                        //
                        Thread.Sleep(10000);
                        // HACK!
                        break;
                    case ACP.ShutterState.shutterClosing:               // Probably a weather initiated closure
                        Logger.Log("**Dome closing when asked to open. Assuming weather closure.", LogLevel.Brief);
                        return false;
                    case ACP.ShutterState.shutterError:
                        throw new Exception("DOME FAILURE: Dome reports shutter error status");
                    case ACP.ShutterState.shutterOpen:                  // It JUST finished opening!
                        Thread.Sleep(5000);                             // Just pause for a sec, then
                        Dome.UnParkHome();                              // Assure slaved!
                        return true;
                    case ACP.ShutterState.shutterOpening:               // Weird, already opening, oh well...
                        break;
                }
                int i;
                for (i = 0; i < 20; i++)                                // Wait up to 5 minutes
                {
                    if (!WeatherSafe)                                   // If the weather went unsafe
                    {
                        Logger.Log("**Weather went unsafe while dome opening.", LogLevel.Brief);
                        return false;
                    }
                    //
                    // The first two cases here probably aren't needed as the weather unsafe 
                    // just got caught. Nonetheless I'm leaving them here as a sort of assert.
                    //
                    switch (Dome.ShutterStatus)
                    {
                        case ACP.ShutterState.shutterClosed:
                            Logger.Log("**Dome closed while opening. Assuming weather closure.", LogLevel.Brief);
                            return false;
                        case ACP.ShutterState.shutterClosing:               // Probably a weather initiated closure
                            Logger.Log("**Dome found closing while opening. Assuming weather closure.", LogLevel.Brief);
                            return false;
                        case ACP.ShutterState.shutterError:
                            throw new Exception("DOME FAILURE: Dome reports shutter error status while opening");
                        case ACP.ShutterState.shutterOpen:                  // Open! OK.
                            break;
                    }
                    if (Dome.ShutterStatus == ACP.ShutterState.shutterOpen)
                        break;                                          // DONE!
                    Thread.Sleep(15000);                                // Wait 15 sec and look again
                }
                if (i >= 20)
                    throw new Exception("Dome failed to open within 5 minutes");
                Dome.UnParkHome();                                      // Assure slaved!
                //
                // Allow Dome to complete its initial slave slew
                //
                Thread.Sleep(15000);                                    // Wait for plenty more than slaving time
                for (i = 0; i < 20; i++)                                // Wait up to 5 minutes
                {
                    if (!WeatherSafe)                                   // If the weather went unsafe
                    {
                        Logger.Log("**Weather went unsafe while dome opening.", LogLevel.Brief);
                        return false;
                    }
                    if (!Dome.Slewing)
                        break;
                    Thread.Sleep(15000);
                }
                if (i >= 20)
                    throw new Exception("Dome failed to complete initial slave slew within 5 minutes");
            }
            return true;
        }

It's all the new tests for hardware closure that are now picking up the "unusual" conditions while the roof is opening. I'll be back on Monday and maybe I'll have ideas. I hate to start putting kludges into the Scheduler for stuff like this (though I already have one new one for weather servers that return from Connected = true yet aren't ready to be called for "a while").

[Mike Pooler]

Bob and Todd
I can confirm this is a problem with my system also. Fosters AstroMC.
In pipes you can see as the roof moves the ascom driver says "opening,,,,opening,,,,Closed,,,,opening,,, opening,,Open".

Not sure if it matters but on the other direction it never says closing just "closed ,,,closed,,,,closed " as the roof moves.

I have a few other issues I am writing a service reqest to Stan Ralph for. I am going to include this problem in my service request.
Mabey Stan can fix the reporte of Closed after the roof is called to open.

The wheels on the bus turn slow at Fosters,,,, Todd I am still waiting to hear back on my last request for the CPS buttons commands not working from the obs weather class... I submited that more than a month ago.

Bob if you can come up with a workaround on Monday for us like a "Util Waituntil" command that might be the quickest fix for the AstroMc problem.
No rush for me nothing but clouds in my future.

Thanks
Mike Pooler

[Bob Denny]

Hi guys --

I believe you :-) My issue is what to do about it:

• I want you to be happy.
• I don't want you to be unable to use Scheduler.
• I have multiple customers who are happy with 3.5's new weather/dome/roof logic.
• I don't have a roof/dome controlled by Foster Systems, therefore any "hack" I might put in could not be tested by me.
• Would it affect my currently happy customers? How long should I leave the hack in the code?
• Would it have unanticipated side effects?

I'll see if I can talk to Foster Systems, and I'll noodle the problem and see if I can come up with a low-risk hack. I might be able to.

Can either of you tell me how long it reports Closed while it's Opening? Could it be more than 30 seconds in Closed state during opening?

[Todd Benko]

Bob

I was out at the observatory today doing testing to get you more information. I used the ACP dome control and status display and cycled the action numerous times to record the following actions.

Time
00:00 The ACP dome open button pressed and the sequence of events starts. ACP dome reports dome as "Closed" and the foster systems driver open button disappears.
00:01 ACP dome status changes from Closed to Opening.
00:03 Foster Systems actually responds now by activating the relay for the motor.
00:04 The dome actually starts to move by the latency of the relay activation. ACP roof display actually changes from "Opening" to "Closed just after the relay clicked.

00:12 The Foster systems driver now reports roof as moving.
00:13 ACP dome status changes from "Closed" to "Opening"
00:31 The roof reaches the open position. The motor stops and almost immediately the driver displays "Open"
00:32 ACP roof status changes from "Opening" to "Open".

So it appears as though there might be an ACP problem that it is actually reporting moving before the actual ascom status of moving is actually available. Second is that the moving status actually occurs at 12 seconds and is just outside the 10 second sleep delay you have in the scheduler code you provided. I would guess that if that was lengthened out to 15 seconds then it might become a don't care.

Todd

[Bob Denny]

So it appears as though there might be an ACP problem that it is actually reporting moving before the actual ascom status of moving is actually available.

Well, the shutter status is not altered within ACP. It is piped straight through to any ACP Dome client or script. Furthermore, it is not legal for a driver to report success to OpenShutter() and not report opening immediately. In other words, the status must be opening (or open if it openes really fast!) if you check it immediately after returning from the call to open it. If this were not the case, the standard would need to include timing hole of indeterminate length during which you could not rely on ShutterStatus. If it reports closed during the time it is opening, then the driver is lying and that is a bug.

This is clearly a Foster Systems issue. Maybe you think I am throwing this over the wall, but I hope the above makes it clear that it cannot be a bug in ACP. Now I'm going to try calling to explain in person.

[Bob Denny]

I tried the 7380 and 5594 numbers. I need to go for today... I'll try tomorrow.

[Todd Benko]

Sorry forgot cell phone at home. No way to get in touch with me while at observatory.

I think there are two seperate issues. The second is the one that is scheduler problem that is just totally the difference between 3.4 and 3.5.

1. I agree the first issue is actually a foster systems problem. Here is the output from pipe on the dome calls with Ascom.

--------------- Mark ---------------


Dome ShutterStatus: Close
Dome ShutterStatus: Close
Dome OpenShutter (initiated)
Dome ShutterStatus: Opening
Dome ShutterStatus: Close
Dome ShutterStatus: Close
Dome ShutterStatus: Opening
Dome ShutterStatus: Opening
Dome ShutterStatus: Opening
Dome ShutterStatus: Opening
Dome ShutterStatus: Open
Dome ShutterStatus: Open
Dome ShutterStatus: Open


--------------- Mark ---------------


Dome ShutterStatus: Open
Dome ShutterStatus: Open
Dome CloseShutter (initiated)
Dome ShutterStatus: Closing
Dome ShutterStatus: Open
Dome ShutterStatus: Open
Dome ShutterStatus: Closing
Dome ShutterStatus: Closing
Dome ShutterStatus: Closing
Dome ShutterStatus: Close
Dome ShutterStatus: Close

So I see no reason why shutter status should report opening or closing right after the initated call and then go back to reporting the open /or closed (depending on the sequence. The actual opening or closing is actually when the magnetic position sensors actually get broken and the moving condition is actually occuring.

Maybe you might have better luck getting Stan to respond to this issue. As it is right now I have to revert back to scheduler 3.4 just to keep operational.

Todd

[Bob Denny]

Thanks for the detailed Pipe traces, very helpful!! The traces prove that this is a Foster driver/controller problem. I'm moving this to the Hardware/Driver section.

The second is the one that is scheduler problem that is just totally the difference between 3.4 and 3.5.

I don't understand this, sorry.

[Bob Denny]

Hi Guys --

I have given consideration to adding a hack to Scheduler 3.5 for this Foster Systems issue, and I'm not going to do it. I hope you'll understand. I don't want to undo all of the testing and experience that a few of the guys have with 3.5 that proves its suitability for weather interruptions during the night. There are a couple of issues around Dawn and Test Shutdown that I have fixed and am now testing before releasing a trial EXE for those people who are affected.

You'll have to roll back to 3.4. You can uninstall 3.5 and install 3.4. If you need that installer it is here

http://download.dc3.com/OlderSchedul...-3.4-Setup.msi