Intermittent safe weather causes state machine confusion

[jamessynge]

The weather at PAN006 was so-so last night. When I checked the logs, I noticed that near the end of the night POCS detected that it was safe and dark, so it opened the dome and unparked. But the weather was detected to be bad as it tried to transition from ready to scheduling, at which point it got stuck in a loop trying to deal with that until it got kicked out for exceeding a 5 loop limit.

Wilfred, can you skim the log and comment?

I0309 09:18:37.398 messaging.py:134     PANCHAT Going to stay parked for half an hour then will try again.
D0309 09:48:44.020 core.py:336          Dark Check: True
D0309 09:48:44.020 core.py:351          Checking weather safety
D0309 09:48:44.021 core.py:371          Weather Safety: True [69 sec old - 2018-03-09 09:47:35.092000]
D0309 09:48:44.021 core.py:267          Resetting observing run attempts
D0309 09:48:44.021 machine.py:267       After calling set_park. Now in parked state
D0309 09:48:44.023 machine.py:309       Source: parked	 Dest: ready
D0309 09:48:44.023 machine.py:171       Transition method: get_ready
D0309 09:48:44.023 machine.py:209       Checking safety for get_ready
D0309 09:48:44.023 machine.py:214       Always safe to move to get_ready
D0309 09:48:44.023 machine.py:253       Before calling get_ready from parked state
I0309 09:48:48.406 messaging.py:134     PANCHAT Ok, I'm all set up and ready to go!
D0309 09:48:48.407 abstract_serial_dome.py:70 Already connected to dome
I0309 09:48:48.740 observatory.py:522   Opening dome
D0309 09:48:56.214 astrohaven.py:183    Got target_feedback, feedback_countdown=1
D0309 09:48:57.125 astrohaven.py:183    Got target_feedback, feedback_countdown=0
D0309 09:49:04.222 astrohaven.py:183    Got target_feedback, feedback_countdown=1
D0309 09:49:04.632 astrohaven.py:183    Got target_feedback, feedback_countdown=0
D0309 09:49:08.032 mount.py:460         Mount unparked
D0309 09:49:08.032 machine.py:267       After calling get_ready. Now in ready state
D0309 09:49:08.036 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:08.037 machine.py:171       Transition method: schedule
D0309 09:49:08.037 machine.py:209       Checking safety for schedule
D0309 09:49:08.143 core.py:336          Dark Check: True
D0309 09:49:08.143 core.py:351          Checking weather safety
D0309 09:49:08.145 core.py:371          Weather Safety: False [10 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:08.145 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:10.649 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:10.649 machine.py:171       Transition method: schedule
D0309 09:49:10.649 machine.py:209       Checking safety for schedule
D0309 09:49:10.734 core.py:336          Dark Check: True
D0309 09:49:10.734 core.py:351          Checking weather safety
D0309 09:49:10.735 core.py:371          Weather Safety: False [13 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:10.735 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:13.238 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:13.238 machine.py:171       Transition method: schedule
D0309 09:49:13.238 machine.py:209       Checking safety for schedule
D0309 09:49:13.342 core.py:336          Dark Check: True
D0309 09:49:13.342 core.py:351          Checking weather safety
D0309 09:49:13.344 core.py:371          Weather Safety: False [15 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:13.344 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:15.848 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:15.849 machine.py:171       Transition method: schedule
D0309 09:49:15.849 machine.py:209       Checking safety for schedule
D0309 09:49:15.939 core.py:336          Dark Check: True
D0309 09:49:15.939 core.py:351          Checking weather safety
D0309 09:49:15.940 core.py:371          Weather Safety: False [18 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:15.941 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:18.445 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:18.445 machine.py:171       Transition method: schedule
D0309 09:49:18.445 machine.py:209       Checking safety for schedule
D0309 09:49:18.537 core.py:336          Dark Check: True
D0309 09:49:18.537 core.py:351          Checking weather safety
D0309 09:49:18.539 core.py:371          Weather Safety: False [20 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:18.539 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:21.043 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:21.043 machine.py:171       Transition method: schedule
D0309 09:49:21.044 machine.py:209       Checking safety for schedule
D0309 09:49:21.136 core.py:336          Dark Check: True
D0309 09:49:21.136 core.py:351          Checking weather safety
D0309 09:49:21.137 core.py:371          Weather Safety: False [23 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:21.137 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
D0309 09:49:23.642 machine.py:309       Source: ready	 Dest: scheduling
D0309 09:49:23.642 machine.py:171       Transition method: schedule
D0309 09:49:23.642 machine.py:209       Checking safety for schedule
D0309 09:49:23.733 core.py:336          Dark Check: True
D0309 09:49:23.733 core.py:351          Checking weather safety
D0309 09:49:23.734 core.py:371          Weather Safety: False [26 sec old - 2018-03-09 09:48:58.053000]
W0309 09:49:23.735 core.py:308          Unsafe conditions: {'is_dark': True, 'good_weather': False, 'free_space': True}
W0309 09:49:23.736 machine.py:141       Stuck in current state for 5 iterations, parking
D0309 09:49:23.736 machine.py:309       Source: ready	 Dest: parking
D0309 09:49:23.736 machine.py:171       Transition method: park
D0309 09:49:23.737 machine.py:209       Checking safety for park
D0309 09:49:23.737 machine.py:214       Always safe to move to park
D0309 09:49:23.737 machine.py:253       Before calling park from ready state
I0309 09:49:28.212 scheduler.py:116     Setting new observation to None
I0309 09:49:28.213 messaging.py:134     PANCHAT Closing dome
D0309 09:49:28.213 abstract_serial_dome.py:70 Already connected to dome
I0309 09:49:28.531 observatory.py:536   Closed dome
D0309 09:49:36.103 astrohaven.py:183    Got target_feedback, feedback_countdown=1
D0309 09:49:36.513 astrohaven.py:183    Got target_feedback, feedback_countdown=0
D0309 09:49:43.791 astrohaven.py:183    Got target_feedback, feedback_countdown=1
D0309 09:49:44.201 astrohaven.py:183    Got target_feedback, feedback_countdown=0
I0309 09:49:47.103 messaging.py:134     PANCHAT I'm takin' it on home and then parking.

[wtgee]

Hm, interesting. Seems like we should have a check for why the state didn't change in the machine run method. Basically if state_changed == False then check if is_safe() == False and if so set the next state to park. The unit should already be parked so it will just pass through that state to parking and then sleep for 30 minutes because of bad weather.

I want to think that through a bit more to make sure there are new repercussions but should be an easy fix. It's odd to me we haven't ever seen a bad weather switch in the middle of a transition like that before though (although, to be fair, maybe we have but just assumed it was "stuck" for some other reason and didn't realize it).

[jamessynge]

See also #527.