2021-08-31T02:48:47.868Z,1630378127.868 [Supervisor](DEBUG): Initializing supervisor.
2021-08-31T02:48:47.875Z,1630378127.875 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-08-31T02:48:47.875Z,1630378127.875 [SyncHandler](INFO): Protected caller Thread ID is 3588
2021-08-31T02:48:47.876Z,1630378127.876 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-08-31T02:48:47.877Z,1630378127.877 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-08-31T02:48:47.877Z,1630378127.877 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3589
2021-08-31T02:48:47.881Z,1630378127.881 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-08-31T02:48:47.899Z,1630378127.899 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-08-31T02:48:47.900Z,1630378127.900 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-08-31T02:48:47.901Z,1630378127.901 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3590
2021-08-31T02:48:47.905Z,1630378127.905 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-08-31T02:48:47.906Z,1630378127.906 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-08-31T02:48:47.906Z,1630378127.906 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3591
2021-08-31T02:48:47.908Z,1630378127.908 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-08-31T02:48:47.909Z,1630378127.909 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-08-31T02:48:47.909Z,1630378127.909 [logger ThreadHandler](INFO): Protected caller Thread ID is 3592
2021-08-31T02:48:47.913Z,1630378127.913 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-08-31T02:48:47.913Z,1630378127.913 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-08-31T02:48:47.915Z,1630378127.915 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-08-31T02:48:48.026Z,1630378128.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-08-31T02:48:48.026Z,1630378128.026 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-08-31T02:48:48.568Z,1630378128.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-08-31T02:48:48.568Z,1630378128.568 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-08-31T02:48:48.770Z,1630378128.770 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-08-31T02:48:48.771Z,1630378128.771 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-08-31T02:48:48.848Z,1630378128.848 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-08-31T02:48:48.966Z,1630378128.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-08-31T02:48:48.966Z,1630378128.966 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-08-31T02:48:49.045Z,1630378129.045 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-08-31T02:48:49.149Z,1630378129.149 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-08-31T02:48:49.150Z,1630378129.150 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-08-31T02:48:49.488Z,1630378129.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-08-31T02:48:49.488Z,1630378129.488 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-08-31T02:48:49.983Z,1630378129.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-08-31T02:48:49.983Z,1630378129.983 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-08-31T02:48:50.124Z,1630378130.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-08-31T02:48:50.124Z,1630378130.124 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-08-31T02:48:50.300Z,1630378130.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-08-31T02:48:50.301Z,1630378130.301 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-08-31T02:48:50.719Z,1630378130.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-08-31T02:48:50.720Z,1630378130.720 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-08-31T02:48:50.947Z,1630378130.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-08-31T02:48:50.948Z,1630378130.948 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-08-31T02:48:51.143Z,1630378131.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-08-31T02:48:51.143Z,1630378131.143 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-08-31T02:48:51.480Z,1630378131.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-08-31T02:48:51.481Z,1630378131.481 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-08-31T02:48:51.808Z,1630378131.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-08-31T02:48:51.810Z,1630378131.810 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2021-08-31T02:48:51.810Z,1630378131.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2021-08-31T02:48:51.892Z,1630378131.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2021-08-31T02:48:52.038Z,1630378132.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2021-08-31T02:48:52.141Z,1630378132.141 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2021-08-31T02:48:52.223Z,1630378132.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2021-08-31T02:48:52.312Z,1630378132.312 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2021-08-31T02:48:52.487Z,1630378132.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2021-08-31T02:48:52.738Z,1630378132.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-08-31T02:48:52.738Z,1630378132.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2021-08-31T02:48:52.829Z,1630378132.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2021-08-31T02:48:52.961Z,1630378132.961 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2021-08-31T02:48:53.468Z,1630378133.468 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2021-08-31T02:48:53.617Z,1630378133.617 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-08-31T02:48:53.625Z,1630378133.625 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-08-31T02:48:53.832Z,1630378133.832 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-08-31T02:48:53.832Z,1630378133.832 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-08-31T02:48:53.885Z,1630378133.885 [VerticalControl](DEBUG): Construct VerticalControl.
2021-08-31T02:48:54.031Z,1630378134.031 [VerticalControl] Loaded
2021-08-31T02:48:54.032Z,1630378134.032 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-08-31T02:48:54.034Z,1630378134.034 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-08-31T02:48:54.072Z,1630378134.072 [HorizontalControl] Loaded
2021-08-31T02:48:54.072Z,1630378134.072 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-08-31T02:48:54.075Z,1630378134.075 [SpeedControl](DEBUG): Construct SpeedControl.
2021-08-31T02:48:54.078Z,1630378134.078 [SpeedControl] Loaded
2021-08-31T02:48:54.078Z,1630378134.078 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-08-31T02:48:54.080Z,1630378134.080 [LoopControl](DEBUG): Construct LoopControl.
2021-08-31T02:48:54.081Z,1630378134.081 [LoopControl] Loaded
2021-08-31T02:48:54.081Z,1630378134.081 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-08-31T02:48:54.081Z,1630378134.081 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-08-31T02:48:54.082Z,1630378134.082 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-08-31T02:48:54.124Z,1630378134.124 [DepthRateCalculator] Loaded
2021-08-31T02:48:54.124Z,1630378134.124 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-08-31T02:48:54.129Z,1630378134.129 [PitchRateCalculator] Loaded
2021-08-31T02:48:54.129Z,1630378134.129 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-08-31T02:48:54.139Z,1630378134.139 [SpeedCalculator] Loaded
2021-08-31T02:48:54.139Z,1630378134.139 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-08-31T02:48:54.152Z,1630378134.152 [TempGradientCalculator] Loaded
2021-08-31T02:48:54.153Z,1630378134.153 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-08-31T02:48:54.157Z,1630378134.157 [YawRateCalculator] Loaded
2021-08-31T02:48:54.157Z,1630378134.157 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-08-31T02:48:54.174Z,1630378134.174 [ElevatorOffsetCalculator] Loaded
2021-08-31T02:48:54.174Z,1630378134.174 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-08-31T02:48:54.174Z,1630378134.174 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-08-31T02:48:54.175Z,1630378134.175 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-08-31T02:48:54.203Z,1630378134.203 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-08-31T02:48:54.203Z,1630378134.203 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-08-31T02:48:54.260Z,1630378134.260 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-08-31T02:48:54.261Z,1630378134.261 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-08-31T02:48:54.574Z,1630378134.574 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-08-31T02:48:54.574Z,1630378134.574 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-08-31T02:48:54.792Z,1630378134.792 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-08-31T02:48:54.792Z,1630378134.792 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-08-31T02:48:56.140Z,1630378136.140 [AHRS_M2] Loaded
2021-08-31T02:48:56.141Z,1630378136.141 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-08-31T02:48:56.499Z,1630378136.499 [BackseatComponent] Loaded
2021-08-31T02:48:56.512Z,1630378136.512 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-08-31T02:48:56.513Z,1630378136.513 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4093A4E0
2021-08-31T02:48:56.513Z,1630378136.513 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3674
2021-08-31T02:48:56.516Z,1630378136.516 [LcmUniversalReporter] Loaded
2021-08-31T02:48:56.516Z,1630378136.516 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-08-31T02:48:57.654Z,1630378137.654 [BPC1] Loaded
2021-08-31T02:48:57.654Z,1630378137.654 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-08-31T02:48:57.748Z,1630378137.748 [DataOverHttps] Loaded
2021-08-31T02:48:57.749Z,1630378137.749 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-08-31T02:48:57.750Z,1630378137.750 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4096A4E0
2021-08-31T02:48:57.750Z,1630378137.750 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3675
2021-08-31T02:48:57.769Z,1630378137.769 [Depth_Keller] Loaded
2021-08-31T02:48:57.769Z,1630378137.769 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-08-31T02:48:57.828Z,1630378137.828 [NAL9602] Loaded
2021-08-31T02:48:57.828Z,1630378137.828 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-08-31T02:48:57.859Z,1630378137.859 [Onboard] Loaded
2021-08-31T02:48:57.859Z,1630378137.859 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-08-31T02:48:57.860Z,1630378137.860 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4099A4E0
2021-08-31T02:48:57.861Z,1630378137.861 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3676
2021-08-31T02:48:57.873Z,1630378137.873 [Power24vConverter] Loaded
2021-08-31T02:48:57.873Z,1630378137.873 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-08-31T02:48:57.886Z,1630378137.886 [Radio_Surface] Loaded
2021-08-31T02:48:57.886Z,1630378137.886 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-08-31T02:48:57.887Z,1630378137.887 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409CA4E0
2021-08-31T02:48:57.887Z,1630378137.887 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3677
2021-08-31T02:48:57.928Z,1630378137.928 [RDI_Pathfinder] Loaded
2021-08-31T02:48:57.928Z,1630378137.928 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-08-31T02:48:58.016Z,1630378138.016 [DAT] Loaded
2021-08-31T02:48:58.017Z,1630378138.017 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-08-31T02:48:58.017Z,1630378138.017 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-08-31T02:48:58.017Z,1630378138.017 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-08-31T02:48:58.138Z,1630378138.138 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-08-31T02:48:58.138Z,1630378138.138 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-08-31T02:48:58.151Z,1630378138.151 [NavChart] Loaded
2021-08-31T02:48:58.151Z,1630378138.151 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-08-31T02:48:58.157Z,1630378138.157 [UniversalFixResidualReporter] Loaded
2021-08-31T02:48:58.157Z,1630378138.157 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-08-31T02:48:58.157Z,1630378138.157 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-08-31T02:48:58.158Z,1630378138.158 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-08-31T02:48:58.299Z,1630378138.299 [SBIT](DEBUG): Construct Startup Built In Test.
2021-08-31T02:48:58.308Z,1630378138.308 [SBIT] Loaded
2021-08-31T02:48:58.308Z,1630378138.308 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-08-31T02:48:58.311Z,1630378138.311 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-08-31T02:48:58.324Z,1630378138.324 [IBIT] Loaded
2021-08-31T02:48:58.324Z,1630378138.324 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-08-31T02:48:58.330Z,1630378138.330 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-08-31T02:48:58.427Z,1630378138.427 [CBIT] Loaded
2021-08-31T02:48:58.427Z,1630378138.427 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-08-31T02:48:58.428Z,1630378138.428 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-08-31T02:48:58.428Z,1630378138.428 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-08-31T02:48:58.557Z,1630378138.557 [BuoyancyServo] Loaded
2021-08-31T02:48:58.558Z,1630378138.558 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-08-31T02:48:58.580Z,1630378138.580 [ElevatorServo] Loaded
2021-08-31T02:48:58.580Z,1630378138.580 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-08-31T02:48:58.599Z,1630378138.599 [MassServo] Loaded
2021-08-31T02:48:58.599Z,1630378138.599 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-08-31T02:48:58.617Z,1630378138.617 [RudderServo] Loaded
2021-08-31T02:48:58.617Z,1630378138.617 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-08-31T02:48:58.634Z,1630378138.634 [ThrusterServo] Loaded
2021-08-31T02:48:58.635Z,1630378138.635 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-08-31T02:48:58.635Z,1630378138.635 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-08-31T02:48:58.635Z,1630378138.635 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-08-31T02:48:58.646Z,1630378138.646 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-08-31T02:48:58.647Z,1630378138.647 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-08-31T02:48:58.824Z,1630378138.824 [CTD_Seabird] Loaded
2021-08-31T02:48:58.824Z,1630378138.824 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-08-31T02:48:58.825Z,1630378138.825 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B024E0
2021-08-31T02:48:58.826Z,1630378138.826 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3678
2021-08-31T02:48:58.845Z,1630378138.845 [PAR_Licor] Loaded
2021-08-31T02:48:58.846Z,1630378138.846 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-08-31T02:48:58.877Z,1630378138.877 [WetLabsBB2FL] Loaded
2021-08-31T02:48:58.877Z,1630378138.877 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-08-31T02:48:58.878Z,1630378138.878 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0
2021-08-31T02:48:58.879Z,1630378138.879 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3679
2021-08-31T02:48:58.898Z,1630378138.898 [WetLabsUBAT] Loaded
2021-08-31T02:48:58.898Z,1630378138.898 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2021-08-31T02:48:58.899Z,1630378138.899 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B624E0
2021-08-31T02:48:58.900Z,1630378138.900 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 3680
2021-08-31T02:48:58.900Z,1630378138.900 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-08-31T02:48:58.907Z,1630378138.907 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-08-31T02:48:58.910Z,1630378138.910 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-08-31T02:48:58.922Z,1630378138.922 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-08-31T02:48:58.923Z,1630378138.923 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B924E0
2021-08-31T02:48:58.923Z,1630378138.923 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3681
2021-08-31T02:48:58.928Z,1630378138.928 [Supervisor](INFO): Main Thread ID is 3587
2021-08-31T02:48:58.928Z,1630378138.928 [Supervisor](DEBUG): Running supervisor.
2021-08-31T02:48:58.929Z,1630378138.929 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3682
2021-08-31T02:48:58.930Z,1630378138.930 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3683
2021-08-31T02:48:58.932Z,1630378138.932 [controlThread ThreadHandler](INFO): Handler Thread ID is 3684
2021-08-31T02:48:58.933Z,1630378138.933 [controlThread](DEBUG): Initializing ControlThread
2021-08-31T02:48:58.934Z,1630378138.934 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-08-31T02:48:58.936Z,1630378138.936 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-08-31T02:48:58.936Z,1630378138.936 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-08-31T02:48:58.937Z,1630378138.937 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-08-31T02:48:58.937Z,1630378138.937 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-08-31T02:48:58.938Z,1630378138.938 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-08-31T02:48:58.938Z,1630378138.938 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-08-31T02:48:58.938Z,1630378138.938 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-08-31T02:48:58.939Z,1630378138.939 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-08-31T02:48:58.939Z,1630378138.939 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-08-31T02:48:58.945Z,1630378138.945 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-08-31T02:48:58.946Z,1630378138.946 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-08-31T02:48:58.946Z,1630378138.946 [SBIT](INFO): Initialize SBIT Component.
2021-08-31T02:48:58.946Z,1630378138.946 [SBIT](IMPORTANT): git: 2021-07-27-19-g53d2d83fc
2021-08-31T02:48:58.947Z,1630378138.947 [SBIT](INFO): git hash: 53d2d83fc7c074d07f3648d92b97b08703138dd2
2021-08-31T02:48:58.947Z,1630378138.947 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-08-31T02:48:58.948Z,1630378138.948 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-08-31T02:48:58.949Z,1630378138.949 [SBIT](INFO): Beginning SBIT in 50.000000 seconds.
2021-08-31T02:48:58.950Z,1630378138.950 [IBIT](INFO): Initialize IBIT Component.
2021-08-31T02:48:58.951Z,1630378138.951 [CBIT](DEBUG): Initialize CBIT Component.
2021-08-31T02:48:58.952Z,1630378138.952 [logger ThreadHandler](INFO): Handler Thread ID is 3685
2021-08-31T02:48:58.964Z,1630378138.964 [CBIT](DEBUG): Initialized mux pins.
2021-08-31T02:48:58.964Z,1630378138.964 [CBIT](DEBUG): Initializing the watchdog timer.
2021-08-31T02:48:58.972Z,1630378138.972 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3686
2021-08-31T02:48:58.984Z,1630378138.984 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3687
2021-08-31T02:48:58.985Z,1630378138.985 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-08-31T02:48:58.988Z,1630378138.988 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2021-08-31T02:48:58.989Z,1630378138.989 [CBIT](DEBUG): Initializing heartbeat.
2021-08-31T02:48:58.996Z,1630378138.996 [Onboard ThreadHandler](INFO): Handler Thread ID is 3688
2021-08-31T02:48:59.013Z,1630378139.013 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3689
2021-08-31T02:48:59.036Z,1630378139.036 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3690
2021-08-31T02:48:59.037Z,1630378139.037 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-08-31T02:48:59.041Z,1630378139.041 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3692
2021-08-31T02:48:59.044Z,1630378139.044 [WetLabsBB2FL](INFO): Powering up
2021-08-31T02:48:59.046Z,1630378139.046 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 3694
2021-08-31T02:48:59.048Z,1630378139.048 [WetLabsUBAT](INFO): Powering up
2021-08-31T02:48:59.049Z,1630378139.049 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3696
2021-08-31T02:48:59.053Z,1630378139.053 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-08-31T02:48:59.053Z,1630378139.053 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-08-31T02:48:59.054Z,1630378139.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-08-31T02:48:59.055Z,1630378139.055 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-08-31T02:48:59.056Z,1630378139.056 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-08-31T02:48:59.060Z,1630378139.060 [CBIT](DEBUG): Deactivating GF circuits.
2021-08-31T02:48:59.060Z,1630378139.060 [CBIT](DEBUG): Deactivating emergency mode.
2021-08-31T02:48:59.096Z,1630378139.096 [CBIT](DEBUG): Backplane powered.
2021-08-31T02:48:59.101Z,1630378139.101 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-08-31T02:48:59.121Z,1630378139.121 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-31T02:48:59.165Z,1630378139.165 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2021-08-31T02:48:59.166Z,1630378139.166 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-08-31T02:48:59.234Z,1630378139.234 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-08-31T02:48:59.235Z,1630378139.235 [Default:A.Wait](DEBUG): Construct Wait.
2021-08-31T02:48:59.237Z,1630378139.237 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-31T02:48:59.277Z,1630378139.277 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-08-31T02:48:59.280Z,1630378139.280 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-08-31T02:48:59.309Z,1630378139.309 [Default:E.Execute](DEBUG): Construct Execute.
2021-08-31T02:48:59.325Z,1630378139.325 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2021-08-31T02:48:59.329Z,1630378139.329 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-08-31T02:48:59.348Z,1630378139.348 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-08-31T02:48:59.418Z,1630378139.418 [Power24vConverter](INFO): Powering up.
2021-08-31T02:48:59.420Z,1630378139.420 [Radio_Surface](INFO): Powering up
2021-08-31T02:48:59.429Z,1630378139.429 [DAT](INFO): Powering up
2021-08-31T02:48:59.429Z,1630378139.429 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:48:59.504Z,1630378139.504 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:48:59.512Z,1630378139.512 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-08-31T02:48:59.513Z,1630378139.513 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:48:59.520Z,1630378139.520 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-08-31T02:48:59.521Z,1630378139.521 [MassServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:48:59.528Z,1630378139.528 [MassServo](DEBUG): Initializing MassServo.
2021-08-31T02:48:59.529Z,1630378139.529 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:48:59.536Z,1630378139.536 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-31T02:48:59.537Z,1630378139.537 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:48:59.544Z,1630378139.544 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-08-31T02:48:59.546Z,1630378139.546 [CommandExec](FAULT): Scheduling is paused
2021-08-31T02:48:59.547Z,1630378139.547 [CBIT](INFO): Critical error at 20210831T024858
2021-08-31T02:48:59.547Z,1630378139.547 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-08-31T02:49:00.548Z,1630378140.548 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-08-31T02:49:00.548Z,1630378140.548 [RudderServo](FAULT): Rudder failed to initialize
2021-08-31T02:49:00.548Z,1630378140.548 [RudderServo] Communications Fault, FailCount= 1
2021-08-31T02:49:00.548Z,1630378140.548 [RudderServo](ERROR): Communications Fault
2021-08-31T02:49:00.648Z,1630378140.648 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-31T02:49:00.794Z,1630378140.794 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-31T02:49:00.795Z,1630378140.795 [RudderServo](INFO): Powering down
2021-08-31T02:49:01.533Z,1630378141.533 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-31T02:49:01.653Z,1630378141.653 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-31T02:49:01.656Z,1630378141.656 [WetLabsBB2FL](INFO): Powering down
2021-08-31T02:49:01.659Z,1630378141.659 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-31T02:49:01.659Z,1630378141.659 [RudderServo] No Fault, FailCount= 1
2021-08-31T02:49:06.070Z,1630378146.070 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-08-31T02:49:08.312Z,1630378148.312 [WetLabsUBAT](INFO): Powering down
2021-08-31T02:49:13.098Z,1630378153.098 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004201
2021-08-31T02:49:21.665Z,1630378161.665 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:49:21.665Z,1630378161.665 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-08-31T02:49:21.665Z,1630378161.665 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:49:21.697Z,1630378161.697 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:49:22.157Z,1630378162.157 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:49:22.929Z,1630378162.929 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:49:22.929Z,1630378162.929 [RDI_Pathfinder] No Fault, FailCount= 1
2021-08-31T02:49:28.129Z,1630378168.129 [NAL9602](INFO): Powering up NAL9602
2021-08-31T02:49:39.067Z,1630378179.067 [NAL9602](INFO): NAL9602 initialized
2021-08-31T02:49:45.507Z,1630378185.507 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:49:45.507Z,1630378185.507 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-08-31T02:49:45.507Z,1630378185.507 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:49:45.539Z,1630378185.539 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:49:45.988Z,1630378185.988 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:49:46.767Z,1630378186.767 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:49:46.767Z,1630378186.767 [RDI_Pathfinder] No Fault, FailCount= 2
2021-08-31T02:49:49.599Z,1630378189.599 [SBIT](IMPORTANT): Beginning Startup BIT
2021-08-31T02:49:49.604Z,1630378189.604 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-31T02:49:57.985Z,1630378197.985 [CommandExec](IMPORTANT): got command failComponent
2021-08-31T02:49:57.985Z,1630378197.985 [CommandExec](IMPORTANT): Failed components:
2021-08-31T02:49:57.985Z,1630378197.985 [CommandExec](IMPORTANT): No failed Components.
2021-08-31T02:49:59.673Z,1630378199.673 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:49:59.673Z,1630378199.673 [DAT] Communications Fault, FailCount= 1
2021-08-31T02:49:59.673Z,1630378199.673 [DAT](ERROR): Communications Fault
2021-08-31T02:49:59.740Z,1630378199.740 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:50:00.087Z,1630378200.087 [DAT](INFO): Powering down
2021-08-31T02:50:00.572Z,1630378200.572 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001234
CHAN A1 (24V): -0.165304
CHAN A2 (12V): -0.006524
CHAN A3 (5V): -0.002007
CHAN B0 (3.3V): 0.000570
CHAN B1 (3.15aV): -0.000125
CHAN B2 (3.15bV): 0.000557
CHAN B3 (GND): 0.001707
OPEN: 0.005096
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-31T02:50:00.933Z,1630378200.933 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:50:00.933Z,1630378200.933 [DAT] No Fault, FailCount= 1
2021-08-31T02:50:03.286Z,1630378203.286 [DAT](INFO): Powering up
2021-08-31T02:50:03.286Z,1630378203.286 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:50:05.803Z,1630378205.803 [CommandExec](IMPORTANT): got command show stack
2021-08-31T02:50:05.803Z,1630378205.803 [CommandExec](IMPORTANT): Behavior Stack:

2021-08-31T02:50:05.803Z,1630378205.803 [MissionManager](IMPORTANT): Mission loaded, but not running.
2021-08-31T02:50:09.346Z,1630378209.346 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:50:09.346Z,1630378209.346 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-08-31T02:50:09.346Z,1630378209.346 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:50:09.461Z,1630378209.461 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:50:09.461Z,1630378209.461 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:50:09.832Z,1630378209.832 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:50:10.015Z,1630378210.015 [CBIT](INFO): Critical error at 20210831T025009
2021-08-31T02:50:16.793Z,1630378216.793 [CommandExec](IMPORTANT): got command failComponent
2021-08-31T02:50:16.793Z,1630378216.793 [CommandExec](IMPORTANT): Failed components:
2021-08-31T02:50:16.793Z,1630378216.793 [CommandExec](IMPORTANT): RDI_Pathfinder: Communications Fault
2021-08-31T02:50:43.329Z,1630378243.329 [SBIT](IMPORTANT): SBIT PASSED
2021-08-31T02:50:43.329Z,1630378243.329 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-08-31T02:50:43.330Z,1630378243.330 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2021-08-31T02:50:43.330Z,1630378243.330 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2021-08-31T02:50:43.331Z,1630378243.331 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2021-08-31T02:50:43.331Z,1630378243.331 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2021-08-31T02:50:43.331Z,1630378243.331 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2021-08-31T02:50:43.331Z,1630378243.331 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=195 cubic_centimeter;

2021-08-31T02:50:43.331Z,1630378243.331 [SBIT](IMPORTANT): VerticalControl.massDefault=7.7 millimeter;

2021-08-31T02:50:43.721Z,1630378243.721 [MissionManager](IMPORTANT): Started mission Startup
2021-08-31T02:50:43.721Z,1630378243.721 [Startup] Running Loop=1
2021-08-31T02:50:43.721Z,1630378243.721 [Startup](DEBUG): Aggregate::initialize Startup
2021-08-31T02:50:43.721Z,1630378243.721 [Startup:A.GoToSurface] Running Loop=1
2021-08-31T02:50:43.721Z,1630378243.721 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T02:50:43.722Z,1630378243.722 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-31T02:50:43.723Z,1630378243.723 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-31T02:50:43.723Z,1630378243.723 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-31T02:50:43.723Z,1630378243.723 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T02:50:43.752Z,1630378243.752 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T02:50:43.757Z,1630378243.757 [Startup:StartupSatComms] Running Loop=1
2021-08-31T02:50:43.757Z,1630378243.757 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-08-31T02:50:43.757Z,1630378243.757 [Startup:StartupSatComms:A] Running Loop=1
2021-08-31T02:50:44.133Z,1630378244.133 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-08-31T02:51:03.474Z,1630378263.474 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:51:03.474Z,1630378263.474 [DAT] Communications Fault, FailCount= 2
2021-08-31T02:51:03.474Z,1630378263.474 [DAT](ERROR): Communications Fault
2021-08-31T02:51:03.527Z,1630378263.527 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:51:03.874Z,1630378263.874 [DAT](INFO): Powering down
2021-08-31T02:51:04.745Z,1630378264.745 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:51:04.745Z,1630378264.745 [DAT] No Fault, FailCount= 2
2021-08-31T02:51:07.120Z,1630378267.120 [DAT](INFO): Powering up
2021-08-31T02:51:07.120Z,1630378267.120 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:51:43.882Z,1630378303.882 [Startup:StartupSatComms:A](INFO): Timed out from 2021-08-31T02:50:43.8Z
2021-08-31T02:51:43.882Z,1630378303.882 [Startup:StartupSatComms:A] Stopped
2021-08-31T02:51:43.882Z,1630378303.882 [Startup:StartupSatComms:B] Running Loop=1
2021-08-31T02:51:44.299Z,1630378304.299 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-31T02:51:51.415Z,1630378311.415 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20210628T224709/Courier0004.lzma
2021-08-31T02:51:52.414Z,1630378312.414 [DataOverHttps](INFO): Moved sent file to Logs/20210628T224709/Courier0004.lzma.bak
2021-08-31T02:51:52.414Z,1630378312.414 [DataOverHttps](INFO): SBD MOMSN=15903162
2021-08-31T02:51:59.241Z,1630378319.241 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-08-31T02:51:59.241Z,1630378319.241 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T02:51:59.270Z,1630378319.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T02:51:59.654Z,1630378319.654 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T02:51:59.654Z,1630378319.654 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-08-31T02:52:07.312Z,1630378327.312 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:52:07.312Z,1630378327.312 [DAT] Communications Fault, FailCount= 3
2021-08-31T02:52:07.312Z,1630378327.312 [DAT](ERROR): Communications Fault
2021-08-31T02:52:07.336Z,1630378327.336 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:52:07.710Z,1630378327.710 [DAT](INFO): Powering down
2021-08-31T02:52:08.089Z,1630378328.089 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20210730T230756/Courier0000.lzma
2021-08-31T02:52:08.631Z,1630378328.631 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:52:08.631Z,1630378328.631 [DAT] No Fault, FailCount= 3
2021-08-31T02:52:09.090Z,1630378329.090 [DataOverHttps](INFO): Moved sent file to Logs/20210730T230756/Courier0000.lzma.bak
2021-08-31T02:52:09.090Z,1630378329.090 [DataOverHttps](INFO): SBD MOMSN=15903165
2021-08-31T02:52:10.938Z,1630378330.938 [DAT](INFO): Powering up
2021-08-31T02:52:10.938Z,1630378330.938 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:52:28.584Z,1630378348.584 [DataOverHttps](INFO): Sending 259 bytes from file Logs/20210831T024847/Courier0000.lzma
2021-08-31T02:52:29.586Z,1630378349.586 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Courier0000.lzma.bak
2021-08-31T02:52:29.586Z,1630378349.586 [DataOverHttps](INFO): SBD MOMSN=15903170
2021-08-31T02:52:44.217Z,1630378364.217 [Startup:StartupSatComms:B](INFO): Timed out from 2021-08-31T02:51:43.9Z
2021-08-31T02:52:44.217Z,1630378364.217 [Startup:StartupSatComms:B] Stopped
2021-08-31T02:52:44.218Z,1630378364.218 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-08-31T02:52:44.218Z,1630378364.218 [Startup:StartupSatComms] Stopped
2021-08-31T02:52:44.218Z,1630378364.218 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-08-31T02:52:44.218Z,1630378364.218 [Startup](INFO): Completed Startup
2021-08-31T02:52:44.219Z,1630378364.219 [MissionManager](INFO): Startup is completed.
2021-08-31T02:52:44.219Z,1630378364.219 [MissionManager](INFO): Uninitializing Mission Startup
2021-08-31T02:52:44.219Z,1630378364.219 [Startup] Stopped
2021-08-31T02:52:44.219Z,1630378364.219 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-08-31T02:52:44.219Z,1630378364.219 [Startup:A.GoToSurface] Stopped
2021-08-31T02:52:44.219Z,1630378364.219 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T02:52:44.601Z,1630378364.601 [MissionManager](IMPORTANT): Started mission Default
2021-08-31T02:52:44.601Z,1630378364.601 [Default] Running Loop=1
2021-08-31T02:52:44.601Z,1630378364.601 [Default](DEBUG): Aggregate::initialize Default
2021-08-31T02:52:44.601Z,1630378364.601 [Default:B.GoToSurface] Running Loop=1
2021-08-31T02:52:44.601Z,1630378364.601 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T02:52:44.602Z,1630378364.602 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-31T02:52:44.602Z,1630378364.602 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-31T02:52:44.602Z,1630378364.602 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-31T02:52:44.603Z,1630378364.603 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T02:52:44.603Z,1630378364.603 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T02:52:44.603Z,1630378364.603 [Default:A.Wait] Running Loop=1
2021-08-31T02:52:44.603Z,1630378364.603 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-08-31T02:52:47.886Z,1630378367.886 [DataOverHttps](INFO): Sending 399 bytes from file Logs/20210615T185312/Express0001.lzma
2021-08-31T02:52:48.886Z,1630378368.886 [DataOverHttps](INFO): Moved sent file to Logs/20210615T185312/Express0001.lzma.bak
2021-08-31T02:52:48.886Z,1630378368.886 [DataOverHttps](INFO): SBD MOMSN=15903175
2021-08-31T02:52:57.949Z,1630378377.949 [Default:A.Wait](INFO): Done Waiting.
2021-08-31T02:52:57.949Z,1630378377.949 [Default:A.Wait] Stopped
2021-08-31T02:52:57.950Z,1630378377.950 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-31T02:52:58.350Z,1630378378.350 [Default:CheckIn] Running Loop=1
2021-08-31T02:52:58.350Z,1630378378.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-31T02:52:58.350Z,1630378378.350 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-31T02:52:58.755Z,1630378378.755 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-08-31T02:53:09.753Z,1630378389.753 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:53:09.753Z,1630378389.753 [RDI_Pathfinder] No Fault, FailCount= 3
2021-08-31T02:53:11.242Z,1630378391.242 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:53:11.243Z,1630378391.243 [DAT] Communications Fault, FailCount= 4
2021-08-31T02:53:11.243Z,1630378391.243 [DAT](ERROR): Communications Fault
2021-08-31T02:53:11.296Z,1630378391.296 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:53:11.646Z,1630378391.646 [DAT](INFO): Powering down
2021-08-31T02:53:12.471Z,1630378392.471 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:53:12.471Z,1630378392.471 [DAT] No Fault, FailCount= 4
2021-08-31T02:53:14.888Z,1630378394.888 [DAT](INFO): Powering up
2021-08-31T02:53:14.889Z,1630378394.889 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:53:22.550Z,1630378402.550 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-08-31T02:53:22.550Z,1630378402.550 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-08-31T02:53:22.550Z,1630378402.550 [RDI_Pathfinder](ERROR): Data Fault
2021-08-31T02:53:22.602Z,1630378402.602 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-08-31T02:53:23.016Z,1630378403.016 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:53:23.788Z,1630378403.788 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:53:23.788Z,1630378403.788 [RDI_Pathfinder] No Fault, FailCount= 1
2021-08-31T02:53:46.400Z,1630378426.400 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:53:46.400Z,1630378426.400 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-08-31T02:53:46.400Z,1630378426.400 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:53:46.427Z,1630378426.427 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:53:46.876Z,1630378426.876 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:53:47.615Z,1630378427.615 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:53:47.616Z,1630378427.616 [RDI_Pathfinder] No Fault, FailCount= 2
2021-08-31T02:54:10.285Z,1630378450.285 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:54:10.285Z,1630378450.285 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-08-31T02:54:10.285Z,1630378450.285 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:54:10.329Z,1630378450.329 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:54:10.330Z,1630378450.330 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:54:10.696Z,1630378450.696 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:54:10.734Z,1630378450.734 [CBIT](INFO): Critical error at 20210831T025410
2021-08-31T02:54:15.082Z,1630378455.082 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:54:15.082Z,1630378455.082 [DAT] Communications Fault, FailCount= 5
2021-08-31T02:54:15.082Z,1630378455.082 [DAT](ERROR): Communications Fault
2021-08-31T02:54:15.160Z,1630378455.160 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:54:15.486Z,1630378455.486 [DAT](INFO): Powering down
2021-08-31T02:54:16.332Z,1630378456.332 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:54:16.332Z,1630378456.332 [DAT] No Fault, FailCount= 5
2021-08-31T02:54:18.750Z,1630378458.750 [DAT](INFO): Powering up
2021-08-31T02:54:18.751Z,1630378458.751 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:54:42.237Z,1630378482.237 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-08-31T02:54:44.069Z,1630378484.069 [DataOverHttps](IMPORTANT): SBD MTMSN=20210831T025443
2021-08-31T02:54:51.548Z,1630378491.548 [DataOverHttps](INFO): Received command: failc
2021-08-31T02:54:51.581Z,1630378491.581 [CommandExec](IMPORTANT): got command failComponent
2021-08-31T02:54:51.581Z,1630378491.581 [CommandExec](IMPORTANT): Failed components:
2021-08-31T02:54:51.581Z,1630378491.581 [CommandExec](IMPORTANT): RDI_Pathfinder: Communications Fault
2021-08-31T02:55:00.448Z,1630378500.448 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-08-31T02:55:00.448Z,1630378500.448 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T02:55:00.459Z,1630378500.459 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T02:55:00.875Z,1630378500.875 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T02:55:00.875Z,1630378500.875 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-08-31T02:55:03.585Z,1630378503.585 [CommandExec](IMPORTANT): got command configSet RDI_Pathfinder.loadAtStartup 0.000000 bool persist
2021-08-31T02:55:03.585Z,1630378503.585 [CommandExec](IMPORTANT): configSet RDI_Pathfinder.loadAtStartup requires a restart to take effect.
2021-08-31T02:55:19.025Z,1630378519.025 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:55:19.025Z,1630378519.025 [DAT] Communications Fault, FailCount= 6
2021-08-31T02:55:19.025Z,1630378519.025 [DAT](ERROR): Communications Fault
2021-08-31T02:55:19.041Z,1630378519.041 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:55:19.406Z,1630378519.406 [DAT](INFO): Powering down
2021-08-31T02:55:20.238Z,1630378520.238 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:55:20.238Z,1630378520.238 [DAT] No Fault, FailCount= 6
2021-08-31T02:55:22.645Z,1630378522.645 [DAT](INFO): Powering up
2021-08-31T02:55:22.645Z,1630378522.645 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:56:03.674Z,1630378563.674 [DataOverHttps](IMPORTANT): SBD MTMSN=20210831T025602
2021-08-31T02:56:11.072Z,1630378571.072 [DataOverHttps](INFO): Received command: sched asap "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m" 3lush 1 2
2021-08-31T02:56:11.084Z,1630378571.084 [CommandExec](IMPORTANT): got command schedule asap "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m" 3lush 1 2.000000
2021-08-31T02:56:11.085Z,1630378571.085 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=3lush
2021-08-31T02:56:11.087Z,1630378571.087 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='3lush'): "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m", ASAP
2021-08-31T02:56:12.074Z,1630378572.074 [DataOverHttps](IMPORTANT): SBD MTMSN=20210831T025611
2021-08-31T02:56:22.228Z,1630378582.228 [DataOverHttps](INFO): Received command: sched asap "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run" 3lush 2 2
2021-08-31T02:56:22.275Z,1630378582.275 [CommandExec](IMPORTANT): got command schedule asap "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run" 3lush 2 2.000000
2021-08-31T02:56:22.275Z,1630378582.275 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=3lush
2021-08-31T02:56:22.277Z,1630378582.277 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='3lush'): "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run", ASAP
2021-08-31T02:56:22.339Z,1630378582.339 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.xml
2021-08-31T02:56:22.339Z,1630378582.339 [MissionManager](INFO): Loading Mission: ./Missions/Transport/keepstation.xml
2021-08-31T02:56:22.449Z,1630378582.449 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2021-08-31T02:56:22.489Z,1630378582.489 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2021-08-31T02:56:22.492Z,1630378582.492 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2021-08-31T02:56:22.494Z,1630378582.494 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2021-08-31T02:56:22.546Z,1630378582.546 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2021-08-31T02:56:22.550Z,1630378582.550 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2021-08-31T02:56:22.585Z,1630378582.585 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2021-08-31T02:56:22.593Z,1630378582.593 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2021-08-31T02:56:22.622Z,1630378582.622 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2021-08-31T02:56:22.639Z,1630378582.639 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2021-08-31T02:56:22.665Z,1630378582.665 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2021-08-31T02:56:22.666Z,1630378582.666 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2021-08-31T02:56:22.899Z,1630378582.899 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 3.000000 h
2021-08-31T02:56:22.910Z,1630378582.910 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:56:22.910Z,1630378582.910 [DAT] Communications Fault, FailCount= 7
2021-08-31T02:56:22.910Z,1630378582.910 [DAT](ERROR): Communications Fault
2021-08-31T02:56:22.930Z,1630378582.930 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2021-08-31T02:56:22.970Z,1630378582.970 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2021-08-31T02:56:22.982Z,1630378582.982 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2021-08-31T02:56:22.994Z,1630378582.994 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2021-08-31T02:56:23.027Z,1630378583.027 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:56:23.029Z,1630378583.029 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2021-08-31T02:56:23.076Z,1630378583.076 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2021-08-31T02:56:23.099Z,1630378583.099 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-31T02:56:23.189Z,1630378583.189 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2021-08-31T02:56:23.338Z,1630378583.338 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2021-08-31T02:56:23.353Z,1630378583.353 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2021-08-31T02:56:23.361Z,1630378583.361 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2021-08-31T02:56:23.362Z,1630378583.362 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2021-08-31T02:56:23.411Z,1630378583.411 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2021-08-31T02:56:23.474Z,1630378583.474 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2021-08-31T02:56:23.551Z,1630378583.551 [keepstation:F.Pitch](DEBUG): Construct.
2021-08-31T02:56:23.583Z,1630378583.583 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy.
2021-08-31T02:56:23.587Z,1630378583.587 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct.
2021-08-31T02:56:23.604Z,1630378583.604 [DAT](INFO): Powering down
2021-08-31T02:56:23.649Z,1630378583.649 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Construct.
2021-08-31T02:56:23.652Z,1630378583.652 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2021-08-31T02:56:23.701Z,1630378583.701 [keepstation:KeepStation:B.Pitch](DEBUG): Construct.
2021-08-31T02:56:23.724Z,1630378583.724 [keepstation:KeepStation:C.KeepStation](DEBUG): Construct KeepStation.
2021-08-31T02:56:23.762Z,1630378583.762 [keepstation:KeepStation:D.Wait](DEBUG): Construct Wait.
2021-08-31T02:56:23.798Z,1630378583.798 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="keepstation">

    <Description>
        Vehicle transits to desired waypoint (or stays put if none is commanded)
        and stays within the specified radius.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>4</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for communications
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="Latitude"><Description>
        Latitude of waypoint to hold. If NaN, hold the latitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Longitude"><Description>
        Longitude of waypoint to hold. If NaN, hold the longitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth held during drift mode
    </Description><Units:meter/><Value>30</Value></DefineArg>

    <DefineArg Name="ApproachDepth"><Description>
        Depth for initial approach to station.
    </Description><Units:meter/><Value>15</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed in drift
        mode
    </Description><Units:meter/><Value>4</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle transit speed.
    </Description><Units:meter_per_second/><Value>0.75</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius of circle around waypoint to hold.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum allowable depth during the mission.
    </Description><Units:meter/><Value>45</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum distance from the shoreline to maintain
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Aggregate Id="TransitToStation">

        <Description>
            Need a separate aggregate for transit if we want to specify a
            different depth for the approach.
        </Description>

        <Sequence/>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="ApproachDepth"/></Setting>
        </Guidance:Pitch>

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
        </Guidance:SetSpeed>

        <Guidance:Waypoint Id="Wpt1">
            <Sequence/>
            <Setting><Guidance:Waypoint.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:Waypoint.longitude/><Arg Name="Longitude"/></Setting>
        </Guidance:Waypoint>

    </Aggregate>

    <Call Id="OnStation" RefId="NeedComms"/>

    <Aggregate Id="KeepStation">

        <Sequence/>

        <Assign><Parallel/><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="Depth"/></Setting>
        </Guidance:Pitch>

        <Guidance:KeepStation>
            <Parallel/>
            <Setting><Guidance:KeepStation.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:KeepStation.longitude/><Arg Name="Longitude"/></Setting>
            <Setting><Guidance:KeepStation.radius/><Arg Name="Radius"/></Setting>
            <Setting><Guidance:KeepStation.speed/><Arg Name="Speed"/></Setting>
        </Guidance:KeepStation>

        <Guidance:Wait>
            <Description>
                Due to the way the KeepStation behavior is currently
                implemented, we must run it in parallel and use a Wait to keep
                from completing the mission before the timeout expires. However,
                this new version of the mission uses a top-level timeout so that
                the entire mission will not run for longer then MissionTimeout.
            </Description>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-08-31T02:56:23.799Z,1630378583.799 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.xml
2021-08-31T02:56:24.249Z,1630378584.249 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-08-31T02:56:24.252Z,1630378584.252 [BPC1](INFO): Received data from all battery sticks.
2021-08-31T02:56:24.325Z,1630378584.325 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T02:56:24.325Z,1630378584.325 [DAT] No Fault, FailCount= 7
2021-08-31T02:56:26.627Z,1630378586.627 [DAT](INFO): Powering up
2021-08-31T02:56:26.627Z,1630378586.627 [DAT](DEBUG): Initializing DAT.
2021-08-31T02:56:33.777Z,1630378593.777 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 1.000000 hour
2021-08-31T02:56:33.777Z,1630378593.777 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 15.000000 minute
2021-08-31T02:56:33.778Z,1630378593.778 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806999 angular_degree
2021-08-31T02:56:33.779Z,1630378593.779 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824364 angular_degree
2021-08-31T02:56:33.780Z,1630378593.780 [CommandExec](IMPORTANT): got command set keepstation.Depth 20.000000 meter
2021-08-31T02:56:37.837Z,1630378597.837 [CommandExec](IMPORTANT): got command set keepstation.DepthDeadband 10.000000 meter
2021-08-31T02:56:37.838Z,1630378597.838 [CommandExec](IMPORTANT): got command set keepstation.Radius 200.000000 meter
2021-08-31T02:56:37.839Z,1630378597.839 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 33.000000 meter
2021-08-31T02:56:37.839Z,1630378597.839 [CommandExec](IMPORTANT): got command run
2021-08-31T02:56:37.865Z,1630378597.865 [CommandExec](IMPORTANT): Running 
2021-08-31T02:56:37.867Z,1630378597.867 [CommandExec](IMPORTANT): got command stop
2021-08-31T02:56:37.867Z,1630378597.867 [CommandExec](IMPORTANT): Scheduling is paused
2021-08-31T02:56:37.867Z,1630378597.867 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2021-08-31T02:56:37.867Z,1630378597.867 [CommandExec](IMPORTANT): got command schedule resume
2021-08-31T02:56:37.880Z,1630378597.880 [CommandExec](IMPORTANT): Scheduling is resumed
2021-08-31T02:56:37.944Z,1630378597.944 [Default] Stopped
2021-08-31T02:56:37.944Z,1630378597.944 [Default](DEBUG): Aggregate::uninitialize Default
2021-08-31T02:56:37.944Z,1630378597.944 [Default:B.GoToSurface] Stopped
2021-08-31T02:56:37.944Z,1630378597.944 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T02:56:37.944Z,1630378597.944 [Default:CheckIn] Stopped
2021-08-31T02:56:37.945Z,1630378597.945 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-31T02:56:37.945Z,1630378597.945 [Default:CheckIn:Read_GPS] Stopped
2021-08-31T02:56:37.945Z,1630378597.945 [MissionManager](IMPORTANT): Started mission keepstation
2021-08-31T02:56:37.945Z,1630378597.945 [keepstation] Running Loop=1
2021-08-31T02:56:37.945Z,1630378597.945 [keepstation](DEBUG): Aggregate::initialize keepstation
2021-08-31T02:56:37.945Z,1630378597.945 [keepstation:StandardEnvelopes] Running Loop=1
2021-08-31T02:56:37.945Z,1630378597.945 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2021-08-31T02:56:37.945Z,1630378597.945 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:F.Pitch] Running Loop=1
2021-08-31T02:56:37.946Z,1630378597.946 [keepstation:F.Pitch](DEBUG): Initialize.
2021-08-31T02:56:37.947Z,1630378597.947 [keepstation:B] Running Loop=1
2021-08-31T02:56:37.947Z,1630378597.947 [keepstation:F.Pitch] Running Loop=1
2021-08-31T02:56:37.956Z,1630378597.956 [keepstation:StandardEnvelopes] Running Loop=1
2021-08-31T02:56:37.956Z,1630378597.956 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2021-08-31T02:56:37.956Z,1630378597.956 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2021-08-31T02:56:37.956Z,1630378597.956 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2021-08-31T02:56:37.957Z,1630378597.957 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:B] Stopped
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:D] Running Loop=1
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:NeedComms] Running Loop=1
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2021-08-31T02:56:37.958Z,1630378597.958 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T02:56:37.959Z,1630378597.959 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2021-08-31T02:56:37.959Z,1630378597.959 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2021-08-31T02:56:37.959Z,1630378597.959 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2021-08-31T02:56:37.960Z,1630378597.960 [keepstation:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T02:56:37.960Z,1630378597.960 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T02:56:37.961Z,1630378597.961 [keepstation:NeedComms:A] Running Loop=1
2021-08-31T02:56:37.961Z,1630378597.961 [keepstation:NeedComms:A](ERROR): data element is not active.
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms:A](INFO): last time_fix was: nan second since 1970/01/01T00:00:00Z 
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms:A] Stopped
2021-08-31T02:56:37.962Z,1630378597.962 [MissionManager](INFO): MissionManager is completed.
2021-08-31T02:56:37.962Z,1630378597.962 [MissionManager](INFO): Uninitializing Mission keepstation
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation] Stopped
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms] Stopped
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms:B.GoToSurface] Stopped
2021-08-31T02:56:37.962Z,1630378597.962 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes] Stopped
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:D] Stopped
2021-08-31T02:56:37.963Z,1630378597.963 [keepstation:F.Pitch] Stopped
2021-08-31T02:56:38.351Z,1630378598.351 [MissionManager](IMPORTANT): Started mission Default
2021-08-31T02:56:38.352Z,1630378598.352 [Default] Running Loop=1
2021-08-31T02:56:38.352Z,1630378598.352 [Default](DEBUG): Aggregate::initialize Default
2021-08-31T02:56:38.352Z,1630378598.352 [Default:B.GoToSurface] Running Loop=1
2021-08-31T02:56:38.352Z,1630378598.352 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T02:56:38.352Z,1630378598.352 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-31T02:56:38.353Z,1630378598.353 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-31T02:56:38.353Z,1630378598.353 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-31T02:56:38.353Z,1630378598.353 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T02:56:38.354Z,1630378598.354 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T02:56:38.354Z,1630378598.354 [Default:A.Wait] Running Loop=1
2021-08-31T02:56:38.354Z,1630378598.354 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-08-31T02:56:51.751Z,1630378611.751 [Default:A.Wait](INFO): Done Waiting.
2021-08-31T02:56:51.751Z,1630378611.751 [Default:A.Wait] Stopped
2021-08-31T02:56:51.751Z,1630378611.751 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-31T02:56:52.138Z,1630378612.138 [Default:CheckIn] Running Loop=1
2021-08-31T02:56:52.138Z,1630378612.138 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-31T02:56:52.138Z,1630378612.138 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-31T02:57:10.334Z,1630378630.334 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:57:10.334Z,1630378630.334 [RDI_Pathfinder] No Fault, FailCount= 3
2021-08-31T02:57:23.210Z,1630378643.210 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-08-31T02:57:23.210Z,1630378643.210 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-08-31T02:57:23.210Z,1630378643.210 [RDI_Pathfinder](ERROR): Data Fault
2021-08-31T02:57:23.228Z,1630378643.228 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-08-31T02:57:23.688Z,1630378643.688 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:57:24.507Z,1630378644.507 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:57:24.507Z,1630378644.507 [RDI_Pathfinder] No Fault, FailCount= 1
2021-08-31T02:57:26.847Z,1630378646.847 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T02:57:26.847Z,1630378646.847 [DAT] Communications Fault, FailCount= 8
2021-08-31T02:57:26.847Z,1630378646.847 [DAT](ERROR): Communications Fault
2021-08-31T02:57:26.879Z,1630378646.879 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T02:57:26.884Z,1630378646.884 [CBIT](FAULT): Communications Fault in component: DAT
2021-08-31T02:57:27.256Z,1630378647.256 [DAT](INFO): Powering down
2021-08-31T02:57:47.046Z,1630378667.046 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:57:47.046Z,1630378667.046 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-08-31T02:57:47.046Z,1630378667.046 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:57:47.063Z,1630378667.063 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:57:47.516Z,1630378667.516 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:57:48.303Z,1630378668.303 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T02:57:48.303Z,1630378668.303 [RDI_Pathfinder] No Fault, FailCount= 2
2021-08-31T02:58:01.633Z,1630378681.633 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-08-31T02:58:01.633Z,1630378681.633 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T02:58:01.645Z,1630378681.645 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T02:58:02.043Z,1630378682.043 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T02:58:02.043Z,1630378682.043 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-08-31T02:58:10.906Z,1630378690.906 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T02:58:10.906Z,1630378690.906 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-08-31T02:58:10.906Z,1630378690.906 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T02:58:10.953Z,1630378690.953 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:58:10.953Z,1630378690.953 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-08-31T02:58:11.372Z,1630378691.372 [RDI_Pathfinder](INFO): Powering down
2021-08-31T02:58:11.413Z,1630378691.413 [CommandExec](FAULT): Scheduling is paused
2021-08-31T02:58:11.413Z,1630378691.413 [CBIT](INFO): Critical error at 20210831T025810
2021-08-31T02:58:30.148Z,1630378710.148 [CommandExec](IMPORTANT): got command configSet DAT.loadAtStartup 0.000000 bool persist
2021-08-31T02:58:30.148Z,1630378710.148 [CommandExec](IMPORTANT): configSet DAT.loadAtStartup requires a restart to take effect.
2021-08-31T02:58:58.444Z,1630378738.444 [CommandExec](IMPORTANT): got command failComponent
2021-08-31T02:58:58.444Z,1630378738.444 [CommandExec](IMPORTANT): Failed components:
2021-08-31T02:58:58.445Z,1630378738.445 [CommandExec](IMPORTANT): RDI_Pathfinder: Communications Fault
2021-08-31T02:58:58.445Z,1630378738.445 [CommandExec](IMPORTANT): DAT: Communications Fault
2021-08-31T02:59:03.865Z,1630378743.865 [CommandExec](IMPORTANT): got command show stack
2021-08-31T02:59:03.865Z,1630378743.865 [CommandExec](IMPORTANT): Behavior Stack:

2021-08-31T02:59:03.865Z,1630378743.865 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2021-08-31T02:59:03.866Z,1630378743.866 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2021-08-31T02:59:42.209Z,1630378782.209 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-08-31T02:59:42.209Z,1630378782.209 [NAL9602] Data Fault, FailCount= 1
2021-08-31T02:59:42.209Z,1630378782.209 [NAL9602](ERROR): Data Fault
2021-08-31T02:59:42.254Z,1630378782.254 [CBIT](ERROR): Data Fault in component: NAL9602
2021-08-31T02:59:42.609Z,1630378782.609 [NAL9602](INFO): Powering down
2021-08-31T02:59:43.446Z,1630378783.446 [CBIT](INFO): Clearing failed state for component NAL9602
2021-08-31T02:59:43.446Z,1630378783.446 [NAL9602] No Fault, FailCount= 1
2021-08-31T03:00:12.913Z,1630378812.913 [NAL9602](INFO): Powering up NAL9602
2021-08-31T03:00:23.821Z,1630378823.821 [NAL9602](INFO): NAL9602 initialized
2021-08-31T03:01:02.649Z,1630378862.649 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-08-31T03:01:02.649Z,1630378862.649 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T03:01:02.668Z,1630378862.668 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T03:01:03.074Z,1630378863.074 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T03:01:03.074Z,1630378863.074 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-08-31T03:01:05.064Z,1630378865.064 [Power24vConverter](INFO): Powering down.
2021-08-31T03:01:11.141Z,1630378871.141 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:01:11.141Z,1630378871.141 [RDI_Pathfinder] No Fault, FailCount= 3
2021-08-31T03:01:11.928Z,1630378871.928 [Power24vConverter](INFO): Powering up.
2021-08-31T03:01:24.052Z,1630378884.052 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-08-31T03:01:24.052Z,1630378884.052 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-08-31T03:01:24.052Z,1630378884.052 [RDI_Pathfinder](ERROR): Data Fault
2021-08-31T03:01:24.072Z,1630378884.072 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-08-31T03:01:24.520Z,1630378884.520 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:01:25.274Z,1630378885.274 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:01:25.274Z,1630378885.274 [RDI_Pathfinder] No Fault, FailCount= 1
2021-08-31T03:01:31.953Z,1630378891.953 [CommandExec](IMPORTANT): got command show stack
2021-08-31T03:01:31.953Z,1630378891.953 [CommandExec](IMPORTANT): Behavior Stack:

2021-08-31T03:01:31.953Z,1630378891.953 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2021-08-31T03:01:31.954Z,1630378891.954 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2021-08-31T03:01:47.888Z,1630378907.888 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T03:01:47.889Z,1630378907.889 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-08-31T03:01:47.889Z,1630378907.889 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T03:01:47.964Z,1630378907.964 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:01:48.373Z,1630378908.373 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:01:49.107Z,1630378909.107 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:01:49.108Z,1630378909.108 [RDI_Pathfinder] No Fault, FailCount= 2
2021-08-31T03:01:52.327Z,1630378912.327 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-31T02:56:52.1Z
2021-08-31T03:01:52.327Z,1630378912.327 [Default:CheckIn:Read_GPS] Stopped
2021-08-31T03:01:52.328Z,1630378912.328 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-31T03:01:52.743Z,1630378912.743 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-31T03:01:58.753Z,1630378918.753 [CommandExec](IMPORTANT): got command show stack
2021-08-31T03:01:58.753Z,1630378918.753 [CommandExec](IMPORTANT): Behavior Stack:

2021-08-31T03:01:58.753Z,1630378918.753 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2021-08-31T03:01:58.754Z,1630378918.754 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_Iridium
2021-08-31T03:01:59.093Z,1630378919.093 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210831T024847/Courier0004.lzma
2021-08-31T03:02:00.094Z,1630378920.094 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Courier0004.lzma.bak
2021-08-31T03:02:00.094Z,1630378920.094 [DataOverHttps](INFO): SBD MOMSN=15903188
2021-08-31T03:02:11.711Z,1630378931.711 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T03:02:11.711Z,1630378931.711 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-08-31T03:02:11.711Z,1630378931.711 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T03:02:11.757Z,1630378931.757 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:02:11.758Z,1630378931.758 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:02:12.176Z,1630378932.176 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:02:12.207Z,1630378932.207 [CBIT](INFO): Critical error at 20210831T030211
2021-08-31T03:02:19.846Z,1630378939.846 [DataOverHttps](INFO): Sending 398 bytes from file Logs/20210622T200939/Express0001.lzma
2021-08-31T03:02:20.846Z,1630378940.846 [DataOverHttps](INFO): Moved sent file to Logs/20210622T200939/Express0001.lzma.bak
2021-08-31T03:02:20.846Z,1630378940.846 [DataOverHttps](INFO): SBD MOMSN=15903192
2021-08-31T03:02:27.214Z,1630378947.214 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T03:02:27.214Z,1630378947.214 [DAT] No Fault, FailCount= 8
2021-08-31T03:02:27.531Z,1630378947.531 [DAT](INFO): Powering up
2021-08-31T03:02:27.531Z,1630378947.531 [DAT](DEBUG): Initializing DAT.
2021-08-31T03:02:40.351Z,1630378960.351 [DataOverHttps](INFO): Sending 912 bytes from file Logs/20210623T215246/Express0001.lzma
2021-08-31T03:02:41.350Z,1630378961.350 [DataOverHttps](INFO): Moved sent file to Logs/20210623T215246/Express0001.lzma.bak
2021-08-31T03:02:41.350Z,1630378961.350 [DataOverHttps](INFO): SBD MOMSN=15903200
2021-08-31T03:02:58.389Z,1630378978.389 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20210623T215246/Express0005.lzma
2021-08-31T03:02:59.390Z,1630378979.390 [DataOverHttps](INFO): Moved sent file to Logs/20210623T215246/Express0005.lzma.bak
2021-08-31T03:02:59.390Z,1630378979.390 [DataOverHttps](INFO): SBD MOMSN=15903222
2021-08-31T03:03:04.376Z,1630378984.376 [CommandExec](IMPORTANT): got command stop
2021-08-31T03:03:04.377Z,1630378984.377 [CommandExec](IMPORTANT): Scheduling is paused
2021-08-31T03:03:16.323Z,1630378996.323 [DataOverHttps](INFO): Sending 951 bytes from file Logs/20210628T224709/Express0001.lzma
2021-08-31T03:03:17.323Z,1630378997.323 [DataOverHttps](INFO): Moved sent file to Logs/20210628T224709/Express0001.lzma.bak
2021-08-31T03:03:17.323Z,1630378997.323 [DataOverHttps](IMPORTANT): SBD MOMSN=15903230, MTMSN=20210831T030316
2021-08-31T03:03:25.812Z,1630379005.812 [DataOverHttps](INFO): Received command: sched "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m" 3lv5a 1 2
2021-08-31T03:03:25.829Z,1630379005.829 [CommandExec](IMPORTANT): got command schedule "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m" 3lv5a 1 2.000000
2021-08-31T03:03:25.829Z,1630379005.829 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=3lv5a
2021-08-31T03:03:25.830Z,1630379005.830 [CommandExec](IMPORTANT): Scheduled #3 (#1 of 2 with id='3lv5a'): "load Transport/keepstation.xml;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 15 min;set keepstation.Latitude 36.807 arcdeg;set keepstation.Longitude -121.82436 arcdeg;set keepstation.Depth 20 m", AFTER MISSION
2021-08-31T03:03:25.831Z,1630379005.831 [CommandExec](FAULT): Scheduling was paused by a command at 2021-08-31T03:03:04Z
2021-08-31T03:03:27.044Z,1630379007.044 [DataOverHttps](IMPORTANT): SBD MTMSN=20210831T030325
2021-08-31T03:03:27.736Z,1630379007.736 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T03:03:27.736Z,1630379007.736 [DAT] Communications Fault, FailCount= 1
2021-08-31T03:03:27.736Z,1630379007.736 [DAT](ERROR): Communications Fault
2021-08-31T03:03:27.798Z,1630379007.798 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T03:03:28.126Z,1630379008.126 [DAT](INFO): Powering down
2021-08-31T03:03:28.989Z,1630379008.989 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T03:03:28.989Z,1630379008.989 [DAT] No Fault, FailCount= 1
2021-08-31T03:03:31.367Z,1630379011.367 [DAT](INFO): Powering up
2021-08-31T03:03:31.368Z,1630379011.368 [DAT](DEBUG): Initializing DAT.
2021-08-31T03:03:34.150Z,1630379014.150 [DataOverHttps](INFO): Sending 2141 bytes from file Logs/20210628T224709/Express0005.lzma
2021-08-31T03:03:34.201Z,1630379014.201 [DataOverHttps](INFO): Received command: sched "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run" 3lv5a 2 2
2021-08-31T03:03:34.231Z,1630379014.231 [CommandExec](IMPORTANT): got command schedule "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run" 3lv5a 2 2.000000
2021-08-31T03:03:34.240Z,1630379014.240 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=3lv5a
2021-08-31T03:03:34.241Z,1630379014.241 [CommandExec](IMPORTANT): Scheduled #4 (#2 of 2 with id='3lv5a'): "set keepstation.DepthDeadband 10 m;set keepstation.Radius 200 m;set keepstation.MaxDepth 33 m;run", AFTER MISSION
2021-08-31T03:03:34.242Z,1630379014.242 [CommandExec](FAULT): Scheduling was paused by a command at 2021-08-31T03:03:04Z
2021-08-31T03:03:35.296Z,1630379015.296 [DataOverHttps](INFO): Moved sent file to Logs/20210628T224709/Express0005.lzma.bak
2021-08-31T03:03:35.296Z,1630379015.296 [DataOverHttps](INFO): SBD MOMSN=15903254
2021-08-31T03:03:50.899Z,1630379030.899 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20210831T024847/Courier0007.lzma
2021-08-31T03:03:51.902Z,1630379031.902 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Courier0007.lzma.bak
2021-08-31T03:03:51.902Z,1630379031.902 [DataOverHttps](INFO): SBD MOMSN=15904128
2021-08-31T03:04:03.712Z,1630379043.712 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-08-31T03:04:03.712Z,1630379043.712 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T03:04:03.734Z,1630379043.734 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T03:04:04.150Z,1630379044.150 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T03:04:04.150Z,1630379044.150 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-08-31T03:04:07.703Z,1630379047.703 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210831T024847/Courier0013.lzma
2021-08-31T03:04:08.706Z,1630379048.706 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Courier0013.lzma.bak
2021-08-31T03:04:08.706Z,1630379048.706 [DataOverHttps](INFO): SBD MOMSN=15904131
2021-08-31T03:04:31.155Z,1630379071.155 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210730T230510/Express0001.lzma
2021-08-31T03:04:31.633Z,1630379071.633 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T03:04:31.633Z,1630379071.633 [DAT] Communications Fault, FailCount= 2
2021-08-31T03:04:31.633Z,1630379071.633 [DAT](ERROR): Communications Fault
2021-08-31T03:04:31.675Z,1630379071.675 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T03:04:32.024Z,1630379072.024 [DAT](INFO): Powering down
2021-08-31T03:04:32.158Z,1630379072.158 [DataOverHttps](INFO): Moved sent file to Logs/20210730T230510/Express0001.lzma.bak
2021-08-31T03:04:32.158Z,1630379072.158 [DataOverHttps](INFO): SBD MOMSN=15904133
2021-08-31T03:04:32.846Z,1630379072.846 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T03:04:32.846Z,1630379072.846 [DAT] No Fault, FailCount= 2
2021-08-31T03:04:35.263Z,1630379075.263 [DAT](INFO): Powering up
2021-08-31T03:04:35.263Z,1630379075.263 [DAT](DEBUG): Initializing DAT.
2021-08-31T03:04:48.955Z,1630379088.955 [DataOverHttps](INFO): Sending 959 bytes from file Logs/20210730T230756/Express0001.lzma
2021-08-31T03:04:52.119Z,1630379092.119 [DataOverHttps](INFO): Moved sent file to Logs/20210730T230756/Express0001.lzma.bak
2021-08-31T03:04:52.119Z,1630379092.119 [DataOverHttps](INFO): SBD MOMSN=15904136
2021-08-31T03:05:08.339Z,1630379108.339 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210730T231339/Express0001.lzma
2021-08-31T03:05:09.346Z,1630379109.346 [DataOverHttps](INFO): Moved sent file to Logs/20210730T231339/Express0001.lzma.bak
2021-08-31T03:05:09.346Z,1630379109.346 [DataOverHttps](INFO): SBD MOMSN=15904162
2021-08-31T03:05:12.038Z,1630379112.038 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:05:12.038Z,1630379112.038 [RDI_Pathfinder] No Fault, FailCount= 3
2021-08-31T03:05:24.934Z,1630379124.934 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2021-08-31T03:05:24.934Z,1630379124.934 [RDI_Pathfinder] Data Fault, FailCount= 1
2021-08-31T03:05:24.934Z,1630379124.934 [RDI_Pathfinder](ERROR): Data Fault
2021-08-31T03:05:25.071Z,1630379125.071 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2021-08-31T03:05:25.424Z,1630379125.424 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:05:26.209Z,1630379126.209 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:05:26.209Z,1630379126.209 [RDI_Pathfinder] No Fault, FailCount= 1
2021-08-31T03:05:28.618Z,1630379128.618 [DataOverHttps](INFO): Sending 1056 bytes from file Logs/20210831T024847/Express0001.lzma
2021-08-31T03:05:29.618Z,1630379129.618 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Express0001.lzma.bak
2021-08-31T03:05:29.618Z,1630379129.618 [DataOverHttps](INFO): SBD MOMSN=15904165
2021-08-31T03:05:35.438Z,1630379135.438 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T03:05:35.438Z,1630379135.438 [DAT] Communications Fault, FailCount= 3
2021-08-31T03:05:35.438Z,1630379135.438 [DAT](ERROR): Communications Fault
2021-08-31T03:05:35.507Z,1630379135.507 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T03:05:35.842Z,1630379135.842 [DAT](INFO): Powering down
2021-08-31T03:05:36.687Z,1630379136.687 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T03:05:36.687Z,1630379136.687 [DAT] No Fault, FailCount= 3
2021-08-31T03:05:39.078Z,1630379139.078 [DAT](INFO): Powering up
2021-08-31T03:05:39.078Z,1630379139.078 [DAT](DEBUG): Initializing DAT.
2021-08-31T03:05:46.702Z,1630379146.702 [DataOverHttps](INFO): Sending 1184 bytes from file Logs/20210831T024847/Express0005.lzma
2021-08-31T03:05:47.702Z,1630379147.702 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Express0005.lzma.bak
2021-08-31T03:05:47.702Z,1630379147.702 [DataOverHttps](INFO): SBD MOMSN=15904196
2021-08-31T03:05:48.771Z,1630379148.771 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T03:05:48.771Z,1630379148.771 [RDI_Pathfinder] Communications Fault, FailCount= 2
2021-08-31T03:05:48.771Z,1630379148.771 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T03:05:48.842Z,1630379148.842 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:05:49.244Z,1630379149.244 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:05:50.058Z,1630379150.058 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-08-31T03:05:50.058Z,1630379150.058 [RDI_Pathfinder] No Fault, FailCount= 2
2021-08-31T03:06:04.645Z,1630379164.645 [DataOverHttps](INFO): Sending 465 bytes from file Logs/20210831T024847/Express0009.lzma
2021-08-31T03:06:06.101Z,1630379166.101 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Express0009.lzma.bak
2021-08-31T03:06:06.101Z,1630379166.101 [DataOverHttps](INFO): SBD MOMSN=15904258
2021-08-31T03:06:12.621Z,1630379172.621 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2021-08-31T03:06:12.621Z,1630379172.621 [RDI_Pathfinder] Communications Fault, FailCount= 3
2021-08-31T03:06:12.621Z,1630379172.621 [RDI_Pathfinder](ERROR): Communications Fault
2021-08-31T03:06:12.762Z,1630379172.762 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:06:12.762Z,1630379172.762 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2021-08-31T03:06:13.100Z,1630379173.100 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:06:13.147Z,1630379173.147 [CommandExec](FAULT): Scheduling is paused for 2 commands
2021-08-31T03:06:13.147Z,1630379173.147 [CBIT](INFO): Critical error at 20210831T030612
2021-08-31T03:06:26.125Z,1630379186.125 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20210831T024847/Express0014.lzma
2021-08-31T03:06:27.129Z,1630379187.129 [DataOverHttps](INFO): Moved sent file to Logs/20210831T024847/Express0014.lzma.bak
2021-08-31T03:06:27.129Z,1630379187.129 [DataOverHttps](IMPORTANT): SBD MOMSN=15904272, MTMSN=20210831T030626
2021-08-31T03:06:30.531Z,1630379190.531 [Default:CheckIn:Read_Iridium] Stopped
2021-08-31T03:06:30.531Z,1630379190.531 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-31T03:06:30.531Z,1630379190.531 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-31T03:06:37.939Z,1630379197.939 [DataOverHttps](INFO): Received command: schedule resume;stop
2021-08-31T03:06:37.943Z,1630379197.943 [CommandExec](IMPORTANT): got command schedule resume
2021-08-31T03:06:37.943Z,1630379197.943 [CommandExec](IMPORTANT): Scheduling is resumed
2021-08-31T03:06:37.943Z,1630379197.943 [CommandExec](IMPORTANT): got command stop
2021-08-31T03:06:37.943Z,1630379197.943 [CommandExec](IMPORTANT): Scheduling is paused for 2 commands
2021-08-31T03:06:39.373Z,1630379199.373 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-08-31T03:06:39.373Z,1630379199.373 [DAT] Communications Fault, FailCount= 4
2021-08-31T03:06:39.373Z,1630379199.373 [DAT](ERROR): Communications Fault
2021-08-31T03:06:39.423Z,1630379199.423 [CBIT](ERROR): Communications Fault in component: DAT
2021-08-31T03:06:39.764Z,1630379199.764 [DAT](INFO): Powering down
2021-08-31T03:06:40.704Z,1630379200.704 [CBIT](INFO): Clearing failed state for component DAT
2021-08-31T03:06:40.712Z,1630379200.712 [DAT] No Fault, FailCount= 4
2021-08-31T03:06:43.001Z,1630379203.001 [DAT](INFO): Powering up
2021-08-31T03:06:43.001Z,1630379203.001 [DAT](DEBUG): Initializing DAT.
2021-08-31T03:06:55.737Z,1630379215.737 [CommandExec](IMPORTANT): got command schedule resume
2021-08-31T03:06:55.738Z,1630379215.738 [CommandExec](IMPORTANT): Scheduling is resumed
2021-08-31T03:06:55.805Z,1630379215.805 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.xml
2021-08-31T03:06:55.806Z,1630379215.806 [MissionManager](INFO): Loading Mission: ./Missions/Transport/keepstation.xml
2021-08-31T03:06:55.878Z,1630379215.878 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2021-08-31T03:06:55.885Z,1630379215.885 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2021-08-31T03:06:55.887Z,1630379215.887 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2021-08-31T03:06:55.890Z,1630379215.890 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2021-08-31T03:06:55.892Z,1630379215.892 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2021-08-31T03:06:55.894Z,1630379215.894 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2021-08-31T03:06:55.896Z,1630379215.896 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2021-08-31T03:06:55.898Z,1630379215.898 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2021-08-31T03:06:55.917Z,1630379215.917 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2021-08-31T03:06:55.919Z,1630379215.919 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2021-08-31T03:06:55.921Z,1630379215.921 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2021-08-31T03:06:55.922Z,1630379215.922 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2021-08-31T03:06:56.059Z,1630379216.059 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 3.000000 h
2021-08-31T03:06:56.062Z,1630379216.062 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2021-08-31T03:06:56.064Z,1630379216.064 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2021-08-31T03:06:56.066Z,1630379216.066 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2021-08-31T03:06:56.072Z,1630379216.072 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2021-08-31T03:06:56.074Z,1630379216.074 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2021-08-31T03:06:56.092Z,1630379216.092 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2021-08-31T03:06:56.106Z,1630379216.106 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-31T03:06:56.143Z,1630379216.143 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2021-08-31T03:06:56.164Z,1630379216.164 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2021-08-31T03:06:56.166Z,1630379216.166 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2021-08-31T03:06:56.168Z,1630379216.168 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2021-08-31T03:06:56.184Z,1630379216.184 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2021-08-31T03:06:56.194Z,1630379216.194 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2021-08-31T03:06:56.219Z,1630379216.219 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2021-08-31T03:06:56.227Z,1630379216.227 [keepstation:F.Pitch](DEBUG): Construct.
2021-08-31T03:06:56.233Z,1630379216.233 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy.
2021-08-31T03:06:56.237Z,1630379216.237 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct.
2021-08-31T03:06:56.241Z,1630379216.241 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Construct.
2021-08-31T03:06:56.244Z,1630379216.244 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2021-08-31T03:06:56.252Z,1630379216.252 [keepstation:KeepStation:B.Pitch](DEBUG): Construct.
2021-08-31T03:06:56.270Z,1630379216.270 [keepstation:KeepStation:C.KeepStation](DEBUG): Construct KeepStation.
2021-08-31T03:06:56.275Z,1630379216.275 [keepstation:KeepStation:D.Wait](DEBUG): Construct Wait.
2021-08-31T03:06:56.294Z,1630379216.294 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="keepstation">

    <Description>
        Vehicle transits to desired waypoint (or stays put if none is commanded)
        and stays within the specified radius.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>4</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for communications
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="Latitude"><Description>
        Latitude of waypoint to hold. If NaN, hold the latitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Longitude"><Description>
        Longitude of waypoint to hold. If NaN, hold the longitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth held during drift mode
    </Description><Units:meter/><Value>30</Value></DefineArg>

    <DefineArg Name="ApproachDepth"><Description>
        Depth for initial approach to station.
    </Description><Units:meter/><Value>15</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed in drift
        mode
    </Description><Units:meter/><Value>4</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle transit speed.
    </Description><Units:meter_per_second/><Value>0.75</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius of circle around waypoint to hold.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum allowable depth during the mission.
    </Description><Units:meter/><Value>45</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum distance from the shoreline to maintain
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Aggregate Id="TransitToStation">

        <Description>
            Need a separate aggregate for transit if we want to specify a
            different depth for the approach.
        </Description>

        <Sequence/>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="ApproachDepth"/></Setting>
        </Guidance:Pitch>

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
        </Guidance:SetSpeed>

        <Guidance:Waypoint Id="Wpt1">
            <Sequence/>
            <Setting><Guidance:Waypoint.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:Waypoint.longitude/><Arg Name="Longitude"/></Setting>
        </Guidance:Waypoint>

    </Aggregate>

    <Call Id="OnStation" RefId="NeedComms"/>

    <Aggregate Id="KeepStation">

        <Sequence/>

        <Assign><Parallel/><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="Depth"/></Setting>
        </Guidance:Pitch>

        <Guidance:KeepStation>
            <Parallel/>
            <Setting><Guidance:KeepStation.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:KeepStation.longitude/><Arg Name="Longitude"/></Setting>
            <Setting><Guidance:KeepStation.radius/><Arg Name="Radius"/></Setting>
            <Setting><Guidance:KeepStation.speed/><Arg Name="Speed"/></Setting>
        </Guidance:KeepStation>

        <Guidance:Wait>
            <Description>
                Due to the way the KeepStation behavior is currently
                implemented, we must run it in parallel and use a Wait to keep
                from completing the mission before the timeout expires. However,
                this new version of the mission uses a top-level timeout so that
                the entire mission will not run for longer then MissionTimeout.
            </Description>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-08-31T03:06:56.294Z,1630379216.294 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.xml
2021-08-31T03:07:03.384Z,1630379223.384 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 1.000000 hour
2021-08-31T03:07:03.385Z,1630379223.385 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 15.000000 minute
2021-08-31T03:07:03.386Z,1630379223.386 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806999 angular_degree
2021-08-31T03:07:03.387Z,1630379223.387 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824364 angular_degree
2021-08-31T03:07:03.387Z,1630379223.387 [CommandExec](IMPORTANT): got command set keepstation.Depth 20.000000 meter
2021-08-31T03:07:04.833Z,1630379224.833 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-08-31T03:07:04.833Z,1630379224.833 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-31T03:07:04.843Z,1630379224.843 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-31T03:07:05.250Z,1630379225.250 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-31T03:07:05.250Z,1630379225.250 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-08-31T03:07:07.505Z,1630379227.505 [CommandExec](IMPORTANT): got command set keepstation.DepthDeadband 10.000000 meter
2021-08-31T03:07:07.506Z,1630379227.506 [CommandExec](IMPORTANT): got command set keepstation.Radius 200.000000 meter
2021-08-31T03:07:07.507Z,1630379227.507 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 33.000000 meter
2021-08-31T03:07:07.507Z,1630379227.507 [CommandExec](IMPORTANT): got command run
2021-08-31T03:07:07.509Z,1630379227.509 [CommandExec](IMPORTANT): Running 
2021-08-31T03:07:07.509Z,1630379227.509 [CommandExec](IMPORTANT): got command stop
2021-08-31T03:07:07.509Z,1630379227.509 [CommandExec](IMPORTANT): Scheduling is paused
2021-08-31T03:07:07.510Z,1630379227.510 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2021-08-31T03:07:07.666Z,1630379227.666 [Default] Stopped
2021-08-31T03:07:07.666Z,1630379227.666 [Default](DEBUG): Aggregate::uninitialize Default
2021-08-31T03:07:07.666Z,1630379227.666 [Default:B.GoToSurface] Stopped
2021-08-31T03:07:07.666Z,1630379227.666 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T03:07:07.666Z,1630379227.666 [Default:CheckIn] Stopped
2021-08-31T03:07:07.666Z,1630379227.666 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-31T03:07:07.666Z,1630379227.666 [Default:CheckIn:C.Wait] Stopped
2021-08-31T03:07:07.666Z,1630379227.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-31T03:07:07.666Z,1630379227.666 [MissionManager](IMPORTANT): Started mission keepstation
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation] Running Loop=1
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation](DEBUG): Aggregate::initialize keepstation
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation:StandardEnvelopes] Running Loop=1
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2021-08-31T03:07:07.667Z,1630379227.667 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:F.Pitch] Running Loop=1
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:F.Pitch](DEBUG): Initialize.
2021-08-31T03:07:07.668Z,1630379227.668 [keepstation:B] Running Loop=1
2021-08-31T03:07:07.669Z,1630379227.669 [keepstation:F.Pitch] Running Loop=1
2021-08-31T03:07:07.669Z,1630379227.669 [keepstation:StandardEnvelopes] Running Loop=1
2021-08-31T03:07:07.669Z,1630379227.669 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2021-08-31T03:07:07.669Z,1630379227.669 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2021-08-31T03:07:07.669Z,1630379227.669 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2021-08-31T03:07:07.670Z,1630379227.670 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:B] Stopped
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:D] Running Loop=1
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:NeedComms] Running Loop=1
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2021-08-31T03:07:07.671Z,1630379227.671 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T03:07:07.672Z,1630379227.672 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2021-08-31T03:07:07.672Z,1630379227.672 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2021-08-31T03:07:07.673Z,1630379227.673 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2021-08-31T03:07:07.673Z,1630379227.673 [keepstation:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T03:07:07.673Z,1630379227.673 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T03:07:07.674Z,1630379227.674 [keepstation:NeedComms:A] Running Loop=1
2021-08-31T03:07:07.675Z,1630379227.675 [keepstation:NeedComms:A](ERROR): data element is not active.
2021-08-31T03:07:07.675Z,1630379227.675 [keepstation:NeedComms:A](INFO): last time_fix was: nan second since 1970/01/01T00:00:00Z 
2021-08-31T03:07:07.675Z,1630379227.675 [keepstation:NeedComms:A] Stopped
2021-08-31T03:07:07.675Z,1630379227.675 [MissionManager](INFO): MissionManager is completed.
2021-08-31T03:07:07.675Z,1630379227.675 [MissionManager](INFO): Uninitializing Mission keepstation
2021-08-31T03:07:07.675Z,1630379227.675 [keepstation] Stopped
2021-08-31T03:07:07.676Z,1630379227.676 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2021-08-31T03:07:07.676Z,1630379227.676 [keepstation:NeedComms] Stopped
2021-08-31T03:07:07.676Z,1630379227.676 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2021-08-31T03:07:07.676Z,1630379227.676 [keepstation:NeedComms:B.GoToSurface] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:D] Stopped
2021-08-31T03:07:07.677Z,1630379227.677 [keepstation:F.Pitch] Stopped
2021-08-31T03:07:08.129Z,1630379228.129 [MissionManager](IMPORTANT): Started mission Default
2021-08-31T03:07:08.129Z,1630379228.129 [Default] Running Loop=1
2021-08-31T03:07:08.129Z,1630379228.129 [Default](DEBUG): Aggregate::initialize Default
2021-08-31T03:07:08.129Z,1630379228.129 [Default:B.GoToSurface] Running Loop=1
2021-08-31T03:07:08.129Z,1630379228.129 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-31T03:07:08.130Z,1630379228.130 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-31T03:07:08.130Z,1630379228.130 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-31T03:07:08.130Z,1630379228.130 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-31T03:07:08.130Z,1630379228.130 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-31T03:07:08.131Z,1630379228.131 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-31T03:07:08.131Z,1630379228.131 [Default:A.Wait] Running Loop=1
2021-08-31T03:07:08.131Z,1630379228.131 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-08-31T03:07:21.401Z,1630379241.401 [Default:A.Wait](INFO): Done Waiting.
2021-08-31T03:07:21.401Z,1630379241.401 [Default:A.Wait] Stopped
2021-08-31T03:07:21.401Z,1630379241.401 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-31T03:07:21.793Z,1630379241.793 [Default:CheckIn] Running Loop=1
2021-08-31T03:07:21.794Z,1630379241.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-31T03:07:21.794Z,1630379241.794 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-31T03:07:23.201Z,1630379243.201 [DataOverHttps](IMPORTANT): SBD MTMSN=20210831T030722
2021-08-31T03:07:30.391Z,1630379250.391 [DataOverHttps](INFO): Received command: restart sys
2021-08-31T03:07:30.417Z,1630379250.417 [CommandExec](IMPORTANT): got command restart system
2021-08-31T03:07:32.469Z,1630379252.469 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:32.470Z,1630379252.470 [CommandExec](INFO): Uninitializing the command scheduler.
2021-08-31T03:07:32.470Z,1630379252.470 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.608Z,1630379252.608 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-08-31T03:07:32.608Z,1630379252.608 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-08-31T03:07:32.608Z,1630379252.608 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.609Z,1630379252.609 [NavChartDb](INFO): Join timeout helper Thread ID is 3815
2021-08-31T03:07:32.832Z,1630379252.832 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:32.833Z,1630379252.833 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.836Z,1630379252.836 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2021-08-31T03:07:32.836Z,1630379252.836 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.836Z,1630379252.836 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 3816
2021-08-31T03:07:32.856Z,1630379252.856 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:32.857Z,1630379252.857 [WetLabsUBAT](INFO): Powering down
2021-08-31T03:07:32.858Z,1630379252.858 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.863Z,1630379252.863 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-08-31T03:07:32.863Z,1630379252.863 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.864Z,1630379252.864 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3817
2021-08-31T03:07:32.916Z,1630379252.916 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:32.916Z,1630379252.916 [WetLabsBB2FL](INFO): Powering down
2021-08-31T03:07:32.917Z,1630379252.917 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.924Z,1630379252.924 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-08-31T03:07:32.924Z,1630379252.924 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:32.924Z,1630379252.924 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3818
2021-08-31T03:07:33.860Z,1630379253.860 [CTD_Seabird](INFO): Powering down
2021-08-31T03:07:33.872Z,1630379253.872 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:33.872Z,1630379253.872 [CTD_Seabird](INFO): Powering down
2021-08-31T03:07:33.884Z,1630379253.884 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:33.888Z,1630379253.888 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-08-31T03:07:33.888Z,1630379253.888 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:33.888Z,1630379253.888 [Radio_Surface](INFO): Join timeout helper Thread ID is 3819
2021-08-31T03:07:34.044Z,1630379254.044 [Radio_Surface](INFO): Powering down
2021-08-31T03:07:34.045Z,1630379254.045 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:34.045Z,1630379254.045 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:34.065Z,1630379254.065 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-08-31T03:07:34.065Z,1630379254.065 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:34.065Z,1630379254.065 [Onboard](INFO): Join timeout helper Thread ID is 3820
2021-08-31T03:07:34.404Z,1630379254.404 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-08-31T03:07:34.976Z,1630379254.976 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:34.976Z,1630379254.976 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:34.992Z,1630379254.992 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-08-31T03:07:34.993Z,1630379254.993 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:34.993Z,1630379254.993 [DataOverHttps](INFO): Join timeout helper Thread ID is 3821
2021-08-31T03:07:35.408Z,1630379255.408 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:35.408Z,1630379255.408 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.428Z,1630379255.428 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-08-31T03:07:35.429Z,1630379255.429 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.430Z,1630379255.430 [BackseatComponent](INFO): Join timeout helper Thread ID is 3822
2021-08-31T03:07:35.576Z,1630379255.576 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:35.576Z,1630379255.576 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.585Z,1630379255.585 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-08-31T03:07:35.585Z,1630379255.585 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.585Z,1630379255.585 [logger](INFO): Join timeout helper Thread ID is 3823
2021-08-31T03:07:35.618Z,1630379255.618 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:35.619Z,1630379255.619 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.637Z,1630379255.637 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-08-31T03:07:35.637Z,1630379255.637 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.637Z,1630379255.637 [CommandLine](INFO): Join timeout helper Thread ID is 3824
2021-08-31T03:07:35.732Z,1630379255.732 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:35.732Z,1630379255.732 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.737Z,1630379255.737 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-08-31T03:07:35.737Z,1630379255.737 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.737Z,1630379255.737 [CommandExec](INFO): Join timeout helper Thread ID is 3825
2021-08-31T03:07:35.738Z,1630379255.738 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-08-31T03:07:35.738Z,1630379255.738 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:35.739Z,1630379255.739 [controlThread](INFO): Join timeout helper Thread ID is 3826
2021-08-31T03:07:35.912Z,1630379255.912 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-31T03:07:35.912Z,1630379255.912 [controlThread](DEBUG): Uninitializing ControlThread
2021-08-31T03:07:35.913Z,1630379255.913 [AHRS_M2](INFO): Powering down
2021-08-31T03:07:35.985Z,1630379255.985 [NAL9602](INFO): Powering down
2021-08-31T03:07:35.986Z,1630379255.986 [RDI_Pathfinder](INFO): Powering down
2021-08-31T03:07:35.987Z,1630379255.987 [DAT](INFO): Powering down
2021-08-31T03:07:36.057Z,1630379256.057 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-08-31T03:07:36.058Z,1630379256.058 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-08-31T03:07:36.058Z,1630379256.058 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-08-31T03:07:36.059Z,1630379256.059 [MissionManager](INFO): Uninitializing Mission Default
2021-08-31T03:07:36.059Z,1630379256.059 [Default] Stopped
2021-08-31T03:07:36.059Z,1630379256.059 [Default](DEBUG): Aggregate::uninitialize Default
2021-08-31T03:07:36.059Z,1630379256.059 [Default:B.GoToSurface] Stopped
2021-08-31T03:07:36.059Z,1630379256.059 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-31T03:07:36.059Z,1630379256.059 [Default:CheckIn] Stopped
2021-08-31T03:07:36.059Z,1630379256.059 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-31T03:07:36.059Z,1630379256.059 [Default:CheckIn:Read_GPS] Stopped
2021-08-31T03:07:36.062Z,1630379256.062 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-08-31T03:07:36.062Z,1630379256.062 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-08-31T03:07:36.063Z,1630379256.063 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-08-31T03:07:36.063Z,1630379256.063 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-08-31T03:07:36.063Z,1630379256.063 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-08-31T03:07:36.063Z,1630379256.063 [BuoyancyServo](INFO): Powering down
2021-08-31T03:07:36.076Z,1630379256.076 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-08-31T03:07:36.076Z,1630379256.076 [ElevatorServo](INFO): Powering down
2021-08-31T03:07:36.077Z,1630379256.077 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-08-31T03:07:36.077Z,1630379256.077 [MassServo](INFO): Powering down
2021-08-31T03:07:36.078Z,1630379256.078 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-31T03:07:36.078Z,1630379256.078 [RudderServo](INFO): Powering down
2021-08-31T03:07:36.079Z,1630379256.079 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-08-31T03:07:36.079Z,1630379256.079 [ThrusterServo](INFO): Powering down
2021-08-31T03:07:36.080Z,1630379256.080 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-08-31T03:07:36.080Z,1630379256.080 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-08-31T03:07:36.080Z,1630379256.080 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-08-31T03:07:36.081Z,1630379256.081 [CBIT](DEBUG): Powering off loads.
2021-08-31T03:07:36.092Z,1630379256.092 [CBIT](DEBUG): Disabling WDT.
2021-08-31T03:07:36.104Z,1630379256.104 [CBIT](DEBUG): Opening all GF detection circuits.
2021-08-31T03:07:36.105Z,1630379256.105 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.167Z,1630379256.167 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.170Z,1630379256.170 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.175Z,1630379256.175 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.225Z,1630379256.225 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.281Z,1630379256.281 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.283Z,1630379256.283 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.286Z,1630379256.286 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.295Z,1630379256.295 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-31T03:07:36.361Z,1630379256.361 [logger ThreadHandler](INFO): Thread cancelled.