2023-12-06T22:29:07.283Z,1701901747.283 [Supervisor](DEBUG): Initializing supervisor.
2023-12-06T22:29:07.287Z,1701901747.287 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-12-06T22:29:07.287Z,1701901747.287 [SyncHandler](INFO): Protected caller Thread ID is 1402
2023-12-06T22:29:07.288Z,1701901747.288 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-12-06T22:29:07.289Z,1701901747.289 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-12-06T22:29:07.289Z,1701901747.289 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1403
2023-12-06T22:29:07.293Z,1701901747.293 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-12-06T22:29:07.310Z,1701901747.310 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-12-06T22:29:07.311Z,1701901747.311 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-12-06T22:29:07.311Z,1701901747.311 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1404
2023-12-06T22:29:07.315Z,1701901747.315 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-12-06T22:29:07.316Z,1701901747.316 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-12-06T22:29:07.317Z,1701901747.317 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1405
2023-12-06T22:29:07.319Z,1701901747.319 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-12-06T22:29:07.320Z,1701901747.320 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-12-06T22:29:07.320Z,1701901747.320 [logger ThreadHandler](INFO): Protected caller Thread ID is 1406
2023-12-06T22:29:07.324Z,1701901747.324 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-12-06T22:29:07.324Z,1701901747.324 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-12-06T22:29:07.326Z,1701901747.326 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-12-06T22:29:07.571Z,1701901747.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-12-06T22:29:07.572Z,1701901747.572 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-12-06T22:29:07.652Z,1701901747.652 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-12-06T22:29:08.102Z,1701901748.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-12-06T22:29:08.102Z,1701901748.102 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-12-06T22:29:08.409Z,1701901748.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-12-06T22:29:08.409Z,1701901748.409 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-12-06T22:29:08.505Z,1701901748.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-12-06T22:29:08.506Z,1701901748.506 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-12-06T22:29:08.881Z,1701901748.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-12-06T22:29:08.881Z,1701901748.881 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-12-06T22:29:09.089Z,1701901749.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-12-06T22:29:09.090Z,1701901749.090 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-12-06T22:29:09.591Z,1701901749.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-12-06T22:29:09.592Z,1701901749.592 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-12-06T22:29:09.725Z,1701901749.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-12-06T22:29:09.726Z,1701901749.726 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-12-06T22:29:09.805Z,1701901749.805 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-12-06T22:29:10.551Z,1701901750.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-12-06T22:29:10.552Z,1701901750.552 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-12-06T22:29:10.909Z,1701901750.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-12-06T22:29:10.910Z,1701901750.910 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-12-06T22:29:11.087Z,1701901751.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-12-06T22:29:11.087Z,1701901751.087 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-12-06T22:29:11.197Z,1701901751.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-12-06T22:29:11.197Z,1701901751.197 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-12-06T22:29:11.416Z,1701901751.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-12-06T22:29:11.417Z,1701901751.417 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-12-06T22:29:11.652Z,1701901751.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-12-06T22:29:11.653Z,1701901751.653 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-12-06T22:29:11.654Z,1701901751.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-12-06T22:29:11.745Z,1701901751.745 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-12-06T22:29:11.832Z,1701901751.832 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-12-06T22:29:11.933Z,1701901751.933 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-12-06T22:29:12.042Z,1701901752.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-12-06T22:29:12.450Z,1701901752.450 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-12-06T22:29:12.570Z,1701901752.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-12-06T22:29:12.730Z,1701901752.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-12-06T22:29:13.097Z,1701901753.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-12-06T22:29:13.242Z,1701901753.242 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-12-06T22:29:13.377Z,1701901753.377 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-12-06T22:29:13.486Z,1701901753.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-12-06T22:29:13.747Z,1701901753.747 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-12-06T22:29:13.748Z,1701901753.748 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-12-06T22:29:13.757Z,1701901753.757 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-12-06T22:29:13.806Z,1701901753.806 [VerticalControl](DEBUG): Construct VerticalControl.
2023-12-06T22:29:13.864Z,1701901753.864 [VerticalControl] Loaded
2023-12-06T22:29:13.865Z,1701901753.865 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-12-06T22:29:13.867Z,1701901753.867 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-12-06T22:29:13.907Z,1701901753.907 [HorizontalControl] Loaded
2023-12-06T22:29:13.907Z,1701901753.907 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-12-06T22:29:13.910Z,1701901753.910 [SpeedControl](DEBUG): Construct SpeedControl.
2023-12-06T22:29:13.913Z,1701901753.913 [SpeedControl] Loaded
2023-12-06T22:29:13.913Z,1701901753.913 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-12-06T22:29:13.916Z,1701901753.916 [LoopControl](DEBUG): Construct LoopControl.
2023-12-06T22:29:13.916Z,1701901753.916 [LoopControl] Loaded
2023-12-06T22:29:13.916Z,1701901753.916 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-12-06T22:29:13.917Z,1701901753.917 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-12-06T22:29:13.917Z,1701901753.917 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-12-06T22:29:13.927Z,1701901753.927 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-12-06T22:29:13.928Z,1701901753.928 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-12-06T22:29:14.068Z,1701901754.068 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-12-06T22:29:14.069Z,1701901754.069 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-12-06T22:29:14.195Z,1701901754.195 [BuoyancyServo] Loaded
2023-12-06T22:29:14.195Z,1701901754.195 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-12-06T22:29:14.215Z,1701901754.215 [ElevatorServo] Loaded
2023-12-06T22:29:14.215Z,1701901754.215 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-12-06T22:29:14.234Z,1701901754.234 [MassServo] Loaded
2023-12-06T22:29:14.234Z,1701901754.234 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-12-06T22:29:14.252Z,1701901754.252 [RudderServo] Loaded
2023-12-06T22:29:14.252Z,1701901754.252 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-12-06T22:29:14.266Z,1701901754.266 [ThrusterHE] Loaded
2023-12-06T22:29:14.266Z,1701901754.266 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-12-06T22:29:14.267Z,1701901754.267 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-12-06T22:29:14.267Z,1701901754.267 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-12-06T22:29:14.378Z,1701901754.378 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-12-06T22:29:14.378Z,1701901754.378 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-12-06T22:29:14.391Z,1701901754.391 [NavChart] Loaded
2023-12-06T22:29:14.391Z,1701901754.391 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-12-06T22:29:14.397Z,1701901754.397 [UniversalFixResidualReporter] Loaded
2023-12-06T22:29:14.397Z,1701901754.397 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-12-06T22:29:14.398Z,1701901754.398 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-12-06T22:29:14.398Z,1701901754.398 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-12-06T22:29:14.452Z,1701901754.452 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-12-06T22:29:14.453Z,1701901754.453 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-12-06T22:29:14.865Z,1701901754.865 [AHRS_M2] Loaded
2023-12-06T22:29:14.865Z,1701901754.865 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-12-06T22:29:15.681Z,1701901755.681 [BPC1] Loaded
2023-12-06T22:29:15.681Z,1701901755.681 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-12-06T22:29:15.753Z,1701901755.753 [DataOverHttps] Loaded
2023-12-06T22:29:15.754Z,1701901755.754 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-12-06T22:29:15.755Z,1701901755.755 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090E4E0
2023-12-06T22:29:15.755Z,1701901755.755 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1491
2023-12-06T22:29:15.776Z,1701901755.776 [Depth_Keller] Loaded
2023-12-06T22:29:15.776Z,1701901755.776 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-12-06T22:29:15.781Z,1701901755.781 [DropWeight] Loaded
2023-12-06T22:29:15.781Z,1701901755.781 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-12-06T22:29:15.842Z,1701901755.842 [NAL9602] Loaded
2023-12-06T22:29:15.842Z,1701901755.842 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-12-06T22:29:15.872Z,1701901755.872 [Onboard] Loaded
2023-12-06T22:29:15.872Z,1701901755.872 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-12-06T22:29:15.873Z,1701901755.873 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093E4E0
2023-12-06T22:29:15.874Z,1701901755.874 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1492
2023-12-06T22:29:15.887Z,1701901755.887 [Power24vConverter] Loaded
2023-12-06T22:29:15.887Z,1701901755.887 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-12-06T22:29:15.900Z,1701901755.900 [Radio_Surface] Loaded
2023-12-06T22:29:15.900Z,1701901755.900 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-12-06T22:29:15.901Z,1701901755.901 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096E4E0
2023-12-06T22:29:15.902Z,1701901755.902 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1493
2023-12-06T22:29:15.915Z,1701901755.915 [Sonardyne_Nano] Loaded
2023-12-06T22:29:15.916Z,1701901755.916 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-12-06T22:29:15.916Z,1701901755.916 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-12-06T22:29:15.917Z,1701901755.917 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-12-06T22:29:15.965Z,1701901755.965 [DepthRateCalculator] Loaded
2023-12-06T22:29:15.965Z,1701901755.965 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-12-06T22:29:15.970Z,1701901755.970 [PitchRateCalculator] Loaded
2023-12-06T22:29:15.970Z,1701901755.970 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-12-06T22:29:15.979Z,1701901755.979 [SpeedCalculator] Loaded
2023-12-06T22:29:15.979Z,1701901755.979 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-12-06T22:29:15.983Z,1701901755.983 [YawRateCalculator] Loaded
2023-12-06T22:29:15.983Z,1701901755.983 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-12-06T22:29:16.001Z,1701901756.001 [ElevatorOffsetCalculator] Loaded
2023-12-06T22:29:16.002Z,1701901756.002 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-12-06T22:29:16.002Z,1701901756.002 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-12-06T22:29:16.003Z,1701901756.003 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-12-06T22:29:16.131Z,1701901756.131 [CANONSampler] Loaded
2023-12-06T22:29:16.131Z,1701901756.131 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-12-06T22:29:16.191Z,1701901756.191 [CTD_Seabird] Loaded
2023-12-06T22:29:16.191Z,1701901756.191 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-12-06T22:29:16.192Z,1701901756.192 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A294E0
2023-12-06T22:29:16.193Z,1701901756.193 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1494
2023-12-06T22:29:16.213Z,1701901756.213 [PAR_Licor] Loaded
2023-12-06T22:29:16.213Z,1701901756.213 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-12-06T22:29:16.252Z,1701901756.252 [WetLabsBB2FL] Loaded
2023-12-06T22:29:16.252Z,1701901756.252 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-12-06T22:29:16.253Z,1701901756.253 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A594E0
2023-12-06T22:29:16.253Z,1701901756.253 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1495
2023-12-06T22:29:16.254Z,1701901756.254 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-12-06T22:29:16.255Z,1701901756.255 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-12-06T22:29:16.281Z,1701901756.281 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-12-06T22:29:16.282Z,1701901756.282 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-12-06T22:29:16.587Z,1701901756.587 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-12-06T22:29:16.587Z,1701901756.587 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-12-06T22:29:16.724Z,1701901756.724 [SBIT](DEBUG): Construct Startup Built In Test.
2023-12-06T22:29:16.733Z,1701901756.733 [SBIT] Loaded
2023-12-06T22:29:16.733Z,1701901756.733 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-12-06T22:29:16.736Z,1701901756.736 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-12-06T22:29:16.749Z,1701901756.749 [IBIT] Loaded
2023-12-06T22:29:16.749Z,1701901756.749 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-12-06T22:29:16.755Z,1701901756.755 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-12-06T22:29:16.857Z,1701901756.857 [CBIT] Loaded
2023-12-06T22:29:16.857Z,1701901756.857 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-12-06T22:29:16.858Z,1701901756.858 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-12-06T22:29:16.858Z,1701901756.858 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-12-06T22:29:16.957Z,1701901756.957 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-12-06T22:29:16.964Z,1701901756.964 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-12-06T22:29:16.966Z,1701901756.966 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-12-06T22:29:16.977Z,1701901756.977 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-12-06T22:29:16.978Z,1701901756.978 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B944E0
2023-12-06T22:29:16.978Z,1701901756.978 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1496
2023-12-06T22:29:16.983Z,1701901756.983 [Supervisor](INFO): Main Thread ID is 1401
2023-12-06T22:29:16.983Z,1701901756.983 [Supervisor](DEBUG): Running supervisor.
2023-12-06T22:29:16.984Z,1701901756.984 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1497
2023-12-06T22:29:16.984Z,1701901756.984 [CommandExec](INFO): Initializing the command executive.
2023-12-06T22:29:16.986Z,1701901756.986 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1498
2023-12-06T22:29:16.988Z,1701901756.988 [controlThread ThreadHandler](INFO): Handler Thread ID is 1499
2023-12-06T22:29:16.988Z,1701901756.988 [controlThread](DEBUG): Initializing ControlThread
2023-12-06T22:29:16.989Z,1701901756.989 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-12-06T22:29:16.991Z,1701901756.991 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-12-06T22:29:16.992Z,1701901756.992 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-12-06T22:29:16.992Z,1701901756.992 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-12-06T22:29:16.994Z,1701901756.994 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-12-06T22:29:16.994Z,1701901756.994 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-12-06T22:29:17.001Z,1701901757.001 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-12-06T22:29:17.002Z,1701901757.002 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-12-06T22:29:17.002Z,1701901757.002 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-12-06T22:29:17.002Z,1701901757.002 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-12-06T22:29:17.003Z,1701901757.003 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-12-06T22:29:17.008Z,1701901757.008 [SBIT](INFO): Initialize SBIT Component.
2023-12-06T22:29:17.008Z,1701901757.008 [SBIT](IMPORTANT): git: 2023-10-12
2023-12-06T22:29:17.008Z,1701901757.008 [SBIT](INFO): git hash: f38038725fad7dfee583a1d6cb07fccd712c5d54
2023-12-06T22:29:17.009Z,1701901757.009 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-12-06T22:29:17.010Z,1701901757.010 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-12-06T22:29:17.011Z,1701901757.011 [SBIT](INFO): Beginning SBIT in 68.000000 seconds.
2023-12-06T22:29:17.011Z,1701901757.011 [IBIT](INFO): Initialize IBIT Component.
2023-12-06T22:29:17.012Z,1701901757.012 [CBIT](DEBUG): Initialize CBIT Component.
2023-12-06T22:29:17.013Z,1701901757.013 [logger ThreadHandler](INFO): Handler Thread ID is 1500
2023-12-06T22:29:17.023Z,1701901757.023 [CBIT](DEBUG): Initialized mux pins.
2023-12-06T22:29:17.023Z,1701901757.023 [CBIT](DEBUG): Initializing the watchdog timer.
2023-12-06T22:29:17.032Z,1701901757.032 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1501
2023-12-06T22:29:17.033Z,1701901757.033 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-12-06T22:29:17.044Z,1701901757.044 [Onboard ThreadHandler](INFO): Handler Thread ID is 1502
2023-12-06T22:29:17.048Z,1701901757.048 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-12-06T22:29:17.048Z,1701901757.048 [CBIT](DEBUG): Initializing heartbeat.
2023-12-06T22:29:17.064Z,1701901757.064 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1503
2023-12-06T22:29:17.080Z,1701901757.080 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1504
2023-12-06T22:29:17.080Z,1701901757.080 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-12-06T22:29:17.085Z,1701901757.085 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1506
2023-12-06T22:29:17.088Z,1701901757.088 [WetLabsBB2FL](INFO): Powering up
2023-12-06T22:29:17.090Z,1701901757.090 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1508
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-12-06T22:29:17.093Z,1701901757.093 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-12-06T22:29:17.094Z,1701901757.094 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-12-06T22:29:17.094Z,1701901757.094 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-12-06T22:29:17.119Z,1701901757.119 [CBIT](DEBUG): Deactivating GF circuits.
2023-12-06T22:29:17.119Z,1701901757.119 [CBIT](DEBUG): Deactivating emergency mode.
2023-12-06T22:29:17.159Z,1701901757.159 [CBIT](DEBUG): Backplane powered.
2023-12-06T22:29:17.160Z,1701901757.160 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-12-06T22:29:17.173Z,1701901757.173 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-12-06T22:29:17.185Z,1701901757.185 [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>


2023-12-06T22:29:17.185Z,1701901757.185 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-12-06T22:29:17.421Z,1701901757.421 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-12-06T22:29:17.422Z,1701901757.422 [Default:A.Wait](DEBUG): Construct Wait.
2023-12-06T22:29:17.452Z,1701901757.452 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-12-06T22:29:17.467Z,1701901757.467 [Radio_Surface](INFO): Powering up
2023-12-06T22:29:17.488Z,1701901757.488 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-12-06T22:29:17.491Z,1701901757.491 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-12-06T22:29:17.521Z,1701901757.521 [Default:E.Execute](DEBUG): Construct Execute.
2023-12-06T22:29:17.545Z,1701901757.545 [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="P4H">
                <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>


2023-12-06T22:29:17.549Z,1701901757.549 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2023-12-06T22:29:17.576Z,1701901757.576 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-12-06T22:29:17.646Z,1701901757.646 [Power24vConverter](INFO): Powering up.
2023-12-06T22:29:17.646Z,1701901757.646 [Sonardyne_Nano](INFO): Initializing.
2023-12-06T22:29:17.667Z,1701901757.667 [CANONSampler](INFO): Powering down
2023-12-06T22:29:17.720Z,1701901757.720 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-12-06T22:29:17.728Z,1701901757.728 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-12-06T22:29:17.729Z,1701901757.729 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-12-06T22:29:17.736Z,1701901757.736 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-12-06T22:29:17.737Z,1701901757.737 [MassServo](DEBUG): Initializing EZServoServo.
2023-12-06T22:29:17.744Z,1701901757.744 [MassServo](DEBUG): Initializing MassServo.
2023-12-06T22:29:17.744Z,1701901757.744 [RudderServo](DEBUG): Initializing EZServoServo.
2023-12-06T22:29:17.756Z,1701901757.756 [RudderServo](DEBUG): Initializing RudderServo.
2023-12-06T22:29:17.756Z,1701901757.756 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-12-06T22:29:17.764Z,1701901757.764 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-12-06T22:29:19.578Z,1701901759.578 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-12-06T22:29:19.699Z,1701901759.699 [WetLabsBB2FL](INFO): Powering down
2023-12-06T22:29:21.220Z,1701901761.220 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109
2023-12-06T22:29:23.492Z,1701901763.492 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-12-06T22:29:31.474Z,1701901771.474 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004723
2023-12-06T22:29:46.245Z,1701901786.245 [NAL9602](INFO): Powering up NAL9602
2023-12-06T22:29:57.153Z,1701901797.153 [NAL9602](INFO): NAL9602 initialized
2023-12-06T22:30:25.533Z,1701901825.533 [SBIT](IMPORTANT): Beginning Startup BIT
2023-12-06T22:30:25.537Z,1701901825.537 [CBIT](IMPORTANT): Beginning ground fault scan
2023-12-06T22:30:36.362Z,1701901836.362 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-12-06T22:30:36.783Z,1701901836.783 [CBIT](IMPORTANT): Beginning ground fault scan
2023-12-06T22:30:47.737Z,1701901847.737 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-12-06T22:30:48.129Z,1701901848.129 [CBIT](IMPORTANT): Beginning ground fault scan
2023-12-06T22:30:59.391Z,1701901859.391 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-12-06T22:30:59.391Z,1701901859.391 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2023-12-06T22:31:19.618Z,1701901879.618 [SBIT](IMPORTANT): SBIT PASSED
2023-12-06T22:31:19.618Z,1701901879.618 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-12-06T22:31:19.619Z,1701901879.619 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-12-06T22:31:19.619Z,1701901879.619 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2023-12-06T22:31:19.619Z,1701901879.619 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=280.419851 cubic_centimeter;

2023-12-06T22:31:19.620Z,1701901879.620 [SBIT](IMPORTANT): VerticalControl.massDefault=-12.074073 millimeter;

2023-12-06T22:31:20.010Z,1701901880.010 [MissionManager](IMPORTANT): Started mission Startup
2023-12-06T22:31:20.010Z,1701901880.010 [Startup] Running Loop=1
2023-12-06T22:31:20.010Z,1701901880.010 [Startup](DEBUG): Aggregate::initialize Startup
2023-12-06T22:31:20.010Z,1701901880.010 [Startup:A.GoToSurface] Running Loop=1
2023-12-06T22:31:20.010Z,1701901880.010 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-06T22:31:20.011Z,1701901880.011 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-06T22:31:20.011Z,1701901880.011 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-06T22:31:20.012Z,1701901880.012 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-06T22:31:20.012Z,1701901880.012 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-06T22:31:20.012Z,1701901880.012 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-06T22:31:20.014Z,1701901880.014 [Startup:StartupSatComms] Running Loop=1
2023-12-06T22:31:20.014Z,1701901880.014 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-12-06T22:31:20.014Z,1701901880.014 [Startup:StartupSatComms:A] Running Loop=1
2023-12-06T22:31:20.402Z,1701901880.402 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-12-06T22:31:42.220Z,1701901902.220 [CommandExec](IMPORTANT): got command failComponent
2023-12-06T22:31:42.220Z,1701901902.220 [CommandExec](IMPORTANT): Failed components:
2023-12-06T22:31:42.220Z,1701901902.220 [CommandExec](IMPORTANT): No failed Components.
2023-12-06T22:32:17.354Z,1701901937.354 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-12-06T22:32:17.354Z,1701901937.354 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:32:17.364Z,1701901937.364 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:32:17.774Z,1701901937.774 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:32:17.774Z,1701901937.774 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-12-06T22:32:20.175Z,1701901940.175 [Startup:StartupSatComms:A](INFO): Timed out from 2023-12-06T22:31:20.0Z
2023-12-06T22:32:20.175Z,1701901940.175 [Startup:StartupSatComms:A] Stopped
2023-12-06T22:32:20.175Z,1701901940.175 [Startup:StartupSatComms:B] Running Loop=1
2023-12-06T22:32:20.586Z,1701901940.586 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-12-06T22:32:26.119Z,1701901946.119 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231205T221258/Courier0007.lzma
2023-12-06T22:32:27.121Z,1701901947.121 [DataOverHttps](INFO): Moved sent file to Logs/20231205T221258/Courier0007.lzma.bak
2023-12-06T22:32:27.121Z,1701901947.121 [DataOverHttps](INFO): SBD MOMSN=19091260
2023-12-06T22:32:42.820Z,1701901962.820 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20231205T222905/Courier0000.lzma
2023-12-06T22:32:43.821Z,1701901963.821 [DataOverHttps](INFO): Moved sent file to Logs/20231205T222905/Courier0000.lzma.bak
2023-12-06T22:32:43.821Z,1701901963.821 [DataOverHttps](INFO): SBD MOMSN=19091262
2023-12-06T22:32:51.613Z,1701901971.613 [CommandExec](IMPORTANT): got command strobe off
2023-12-06T22:32:51.613Z,1701901971.613 [CommandExec](IMPORTANT): Deactivating strobe
2023-12-06T22:32:59.516Z,1701901979.516 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20231206T222907/Courier0000.lzma
2023-12-06T22:33:00.517Z,1701901980.517 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0000.lzma.bak
2023-12-06T22:33:00.517Z,1701901980.517 [DataOverHttps](INFO): SBD MOMSN=19091267
2023-12-06T22:33:16.859Z,1701901996.859 [DataOverHttps](INFO): Sending 126 bytes from file Logs/20231205T221258/Express0008.lzma
2023-12-06T22:33:17.862Z,1701901997.862 [DataOverHttps](INFO): Moved sent file to Logs/20231205T221258/Express0008.lzma.bak
2023-12-06T22:33:17.862Z,1701901997.862 [DataOverHttps](INFO): SBD MOMSN=19091270
2023-12-06T22:33:20.374Z,1701902000.374 [Startup:StartupSatComms:B](INFO): Timed out from 2023-12-06T22:32:20.2Z
2023-12-06T22:33:20.375Z,1701902000.375 [Startup:StartupSatComms:B] Stopped
2023-12-06T22:33:20.375Z,1701902000.375 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-12-06T22:33:20.375Z,1701902000.375 [Startup:StartupSatComms] Stopped
2023-12-06T22:33:20.375Z,1701902000.375 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-12-06T22:33:20.376Z,1701902000.376 [Startup](INFO): Completed Startup
2023-12-06T22:33:20.376Z,1701902000.376 [MissionManager](INFO): Startup is completed.
2023-12-06T22:33:20.376Z,1701902000.376 [MissionManager](INFO): Uninitializing Mission Startup
2023-12-06T22:33:20.376Z,1701902000.376 [Startup] Stopped
2023-12-06T22:33:20.377Z,1701902000.377 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-12-06T22:33:20.377Z,1701902000.377 [Startup:A.GoToSurface] Stopped
2023-12-06T22:33:20.377Z,1701902000.377 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-12-06T22:33:20.785Z,1701902000.785 [MissionManager](IMPORTANT): Started mission Default
2023-12-06T22:33:20.785Z,1701902000.785 [Default] Running Loop=1
2023-12-06T22:33:20.785Z,1701902000.785 [Default](DEBUG): Aggregate::initialize Default
2023-12-06T22:33:20.785Z,1701902000.785 [Default:B.GoToSurface] Running Loop=1
2023-12-06T22:33:20.785Z,1701902000.785 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-06T22:33:20.785Z,1701902000.785 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-06T22:33:20.786Z,1701902000.786 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-06T22:33:20.786Z,1701902000.786 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-06T22:33:20.786Z,1701902000.786 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-06T22:33:20.786Z,1701902000.786 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-06T22:33:20.787Z,1701902000.787 [Default:A.Wait] Running Loop=1
2023-12-06T22:33:20.787Z,1701902000.787 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-12-06T22:33:30.461Z,1701902010.461 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-12-06T22:33:33.506Z,1701902013.506 [DataOverHttps](INFO): Sending 859 bytes from file Logs/20231205T222905/Express0001.lzma
2023-12-06T22:33:34.135Z,1701902014.135 [Default:A.Wait](INFO): Done Waiting.
2023-12-06T22:33:34.135Z,1701902014.135 [Default:A.Wait] Stopped
2023-12-06T22:33:34.135Z,1701902014.135 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T22:33:34.506Z,1701902014.506 [DataOverHttps](INFO): Moved sent file to Logs/20231205T222905/Express0001.lzma.bak
2023-12-06T22:33:34.506Z,1701902014.506 [DataOverHttps](INFO): SBD MOMSN=19091274
2023-12-06T22:33:34.555Z,1701902014.555 [Default:CheckIn] Running Loop=1
2023-12-06T22:33:34.555Z,1701902014.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T22:33:34.555Z,1701902014.555 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T22:33:34.946Z,1701902014.946 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-12-06T22:34:17.320Z,1701902057.320 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-06T22:34:17.327Z,1701902057.327 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 6.
2023-12-06T22:34:17.331Z,1701902057.331 [BPC1](INFO): Received data from all battery sticks.
2023-12-06T22:35:00.558Z,1701902100.558 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-06T22:35:18.359Z,1701902118.359 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-12-06T22:35:18.359Z,1701902118.359 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:35:18.369Z,1701902118.369 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:35:18.783Z,1701902118.783 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:35:18.783Z,1701902118.783 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-12-06T22:35:44.297Z,1701902144.297 [CommandExec](IMPORTANT): got command failComponent
2023-12-06T22:35:44.297Z,1701902144.297 [CommandExec](IMPORTANT): Failed components:
2023-12-06T22:35:44.297Z,1701902144.297 [CommandExec](IMPORTANT): No failed Components.
2023-12-06T22:38:19.347Z,1701902299.347 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-12-06T22:38:19.347Z,1701902299.347 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:38:19.358Z,1701902299.358 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:38:19.747Z,1701902299.747 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:38:19.747Z,1701902299.747 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-12-06T22:38:34.708Z,1701902314.708 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-06T22:33:34.6Z
2023-12-06T22:38:34.708Z,1701902314.708 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T22:38:34.708Z,1701902314.708 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T22:38:35.128Z,1701902315.128 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-12-06T22:38:37.108Z,1701902317.108 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20231206T222907/Courier0004.lzma
2023-12-06T22:38:38.110Z,1701902318.110 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0004.lzma.bak
2023-12-06T22:38:38.110Z,1701902318.110 [DataOverHttps](INFO): SBD MOMSN=19091305
2023-12-06T22:38:56.097Z,1701902336.097 [DataOverHttps](INFO): Sending 845 bytes from file Logs/20231206T222907/Express0001.lzma
2023-12-06T22:38:57.098Z,1701902337.098 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0001.lzma.bak
2023-12-06T22:38:57.098Z,1701902337.098 [DataOverHttps](INFO): SBD MOMSN=19091307
2023-12-06T22:39:12.508Z,1701902352.508 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20231206T222907/Express0005.lzma
2023-12-06T22:39:13.510Z,1701902353.510 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0005.lzma.bak
2023-12-06T22:39:13.510Z,1701902353.510 [DataOverHttps](INFO): SBD MOMSN=19091333
2023-12-06T22:39:14.774Z,1701902354.774 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T22:39:14.774Z,1701902354.774 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T22:39:14.774Z,1701902354.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T22:39:18.808Z,1701902358.808 [Power24vConverter](INFO): Powering down.
2023-12-06T22:39:58.790Z,1701902398.790 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-12-06T22:39:58.790Z,1701902398.790 [NAL9602] Data Fault, FailCount= 1
2023-12-06T22:39:58.790Z,1701902398.790 [NAL9602](ERROR): Data Fault
2023-12-06T22:39:58.825Z,1701902398.825 [CBIT](ERROR): Data Fault in component: NAL9602
2023-12-06T22:39:59.194Z,1701902399.194 [NAL9602](INFO): Powering down
2023-12-06T22:40:00.020Z,1701902400.020 [CBIT](INFO): Clearing failed state for component NAL9602
2023-12-06T22:40:00.020Z,1701902400.020 [NAL9602] No Fault, FailCount= 1
2023-12-06T22:40:29.493Z,1701902429.493 [NAL9602](INFO): Powering up NAL9602
2023-12-06T22:40:40.398Z,1701902440.398 [NAL9602](INFO): NAL9602 initialized
2023-12-06T22:41:20.463Z,1701902480.463 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-12-06T22:41:20.463Z,1701902480.463 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:41:20.530Z,1701902480.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:41:20.887Z,1701902480.887 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:41:20.887Z,1701902480.887 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-12-06T22:44:15.422Z,1701902655.422 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-06T22:44:15.422Z,1701902655.422 [Default:CheckIn:C.Wait] Stopped
2023-12-06T22:44:15.422Z,1701902655.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T22:44:15.422Z,1701902655.422 [Default:CheckIn:D] Running Loop=1
2023-12-06T22:44:15.846Z,1701902655.846 [Default:CheckIn:D] Stopped
2023-12-06T22:44:15.846Z,1701902655.846 [Default:CheckIn:E] Running Loop=1
2023-12-06T22:44:16.247Z,1701902656.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.917693 min 
2023-12-06T22:44:16.247Z,1701902656.247 [Default:CheckIn:E] Stopped
2023-12-06T22:44:16.247Z,1701902656.247 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-06T22:44:16.247Z,1701902656.247 [Default:CheckIn] Stopped
2023-12-06T22:44:16.247Z,1701902656.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-06T22:44:16.248Z,1701902656.248 [Default:CheckIn](INFO): Running loop #2
2023-12-06T22:44:16.248Z,1701902656.248 [Default:CheckIn] Running Loop=2
2023-12-06T22:44:16.248Z,1701902656.248 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T22:44:16.248Z,1701902656.248 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T22:44:21.499Z,1701902661.499 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-12-06T22:44:21.499Z,1701902661.499 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:44:21.522Z,1701902661.522 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:44:21.936Z,1701902661.936 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:44:21.937Z,1701902661.937 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-12-06T22:47:22.366Z,1701902842.366 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-12-06T22:47:22.366Z,1701902842.366 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-06T22:47:22.376Z,1701902842.376 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-06T22:47:22.782Z,1701902842.782 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-06T22:47:22.782Z,1701902842.782 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-12-06T22:47:34.466Z,1701902854.466 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224734.00,A,3648.16932,N,12147.29966,W,0.816,315.71,061223,,,A*77
2023-12-06T22:47:34.478Z,1701902854.478 [NAL9602](INFO): GPS fix at 20231206T224734: (36.802822, -121.788328)
2023-12-06T22:47:34.490Z,1701902854.490 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T22:47:34.490Z,1701902854.490 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T22:47:43.631Z,1701902863.631 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20231206T222907/Courier0007.lzma
2023-12-06T22:47:44.744Z,1701902864.744 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0007.lzma.bak
2023-12-06T22:47:44.744Z,1701902864.744 [DataOverHttps](INFO): SBD MOMSN=19091343
2023-12-06T22:48:01.079Z,1701902881.079 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20231206T222907/Express0008.lzma
2023-12-06T22:48:02.081Z,1701902882.081 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0008.lzma.bak
2023-12-06T22:48:02.081Z,1701902882.081 [DataOverHttps](INFO): SBD MOMSN=19091346
2023-12-06T22:48:03.563Z,1701902883.563 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T22:48:03.563Z,1701902883.563 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T22:48:03.563Z,1701902883.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T22:48:07.188Z,1701902887.188 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-06T22:50:12.672Z,1701903012.672 [DataOverHttps](IMPORTANT): SBD MTMSN=20231206T225012
2023-12-06T22:50:21.303Z,1701903021.303 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.tl
2023-12-06T22:50:21.367Z,1701903021.367 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-12-06T22:50:21.379Z,1701903021.379 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-12-06T22:50:21.379Z,1701903021.379 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Maintenance/tank_ballast_and_trim.tx
2023-12-06T22:50:21.522Z,1701903021.522 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2023-12-06T22:50:21.537Z,1701903021.537 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2023-12-06T22:50:21.541Z,1701903021.541 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2023-12-06T22:50:21.544Z,1701903021.544 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2023-12-06T22:50:21.547Z,1701903021.547 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2023-12-06T22:50:21.549Z,1701903021.549 [MissionManager](INFO): DefineArg ballast_and_trim.TargetDepthTimeout = 20.000000 min
2023-12-06T22:50:21.584Z,1701903021.584 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2023-12-06T22:50:21.587Z,1701903021.587 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2023-12-06T22:50:21.590Z,1701903021.590 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2023-12-06T22:50:21.609Z,1701903021.609 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2023-12-06T22:50:21.612Z,1701903021.612 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2023-12-06T22:50:21.635Z,1701903021.635 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2023-12-06T22:50:21.638Z,1701903021.638 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2023-12-06T22:50:21.639Z,1701903021.639 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.tl
2023-12-06T22:50:21.639Z,1701903021.639 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/Science.tx
2023-12-06T22:50:22.383Z,1701903022.383 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2023-12-06T22:50:22.386Z,1701903022.386 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2023-12-06T22:50:22.416Z,1701903022.416 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2023-12-06T22:50:22.418Z,1701903022.418 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2023-12-06T22:50:22.421Z,1701903022.421 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2023-12-06T22:50:22.440Z,1701903022.440 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2023-12-06T22:50:22.442Z,1701903022.442 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2023-12-06T22:50:22.454Z,1701903022.454 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2023-12-06T22:50:22.461Z,1701903022.461 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2023-12-06T22:50:22.472Z,1701903022.472 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2023-12-06T22:50:22.483Z,1701903022.483 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2023-12-06T22:50:22.497Z,1701903022.497 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2023-12-06T22:50:22.557Z,1701903022.557 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2023-12-06T22:50:22.572Z,1701903022.572 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2023-12-06T22:50:22.575Z,1701903022.575 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2023-12-06T22:50:22.578Z,1701903022.578 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2023-12-06T22:50:22.613Z,1701903022.613 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2023-12-06T22:50:22.617Z,1701903022.617 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2023-12-06T22:50:22.631Z,1701903022.631 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2023-12-06T22:50:22.634Z,1701903022.634 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2023-12-06T22:50:22.672Z,1701903022.672 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2023-12-06T22:50:22.674Z,1701903022.674 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2023-12-06T22:50:22.677Z,1701903022.677 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2023-12-06T22:50:22.700Z,1701903022.700 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2023-12-06T22:50:22.703Z,1701903022.703 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2023-12-06T22:50:22.706Z,1701903022.706 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2023-12-06T22:50:22.725Z,1701903022.725 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlThreshTriggerActive = 0 bool
2023-12-06T22:50:22.728Z,1701903022.728 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlLowerThresh = nan ug/l
2023-12-06T22:50:22.731Z,1701903022.731 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlUpperThresh = nan ug/l
2023-12-06T22:50:22.753Z,1701903022.753 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesThresh = 5.000000 count
2023-12-06T22:50:22.756Z,1701903022.756 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = nan ug/l
2023-12-06T22:50:22.787Z,1701903022.787 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = nan m
2023-12-06T22:50:22.790Z,1701903022.790 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = nan degC
2023-12-06T22:50:22.793Z,1701903022.793 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2023-12-06T22:50:22.805Z,1701903022.805 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2023-12-06T22:50:22.808Z,1701903022.808 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = nan umol/l
2023-12-06T22:50:22.811Z,1701903022.811 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = nan m
2023-12-06T22:50:22.838Z,1701903022.838 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2023-12-06T22:50:22.841Z,1701903022.841 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2023-12-06T22:50:22.860Z,1701903022.860 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = nan kg/m3
2023-12-06T22:50:22.876Z,1701903022.876 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = nan m
2023-12-06T22:50:22.879Z,1701903022.879 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2023-12-06T22:50:22.882Z,1701903022.882 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2023-12-06T22:50:22.901Z,1701903022.901 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = nan ppb
2023-12-06T22:50:22.904Z,1701903022.904 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = nan m
2023-12-06T22:50:22.953Z,1701903022.953 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2023-12-06T22:50:22.965Z,1701903022.965 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2023-12-06T22:50:22.968Z,1701903022.968 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2023-12-06T22:50:22.971Z,1701903022.971 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2023-12-06T22:50:23.002Z,1701903023.002 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = nan psu
2023-12-06T22:50:23.005Z,1701903023.005 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = nan m
2023-12-06T22:50:23.032Z,1701903023.032 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = nan degC
2023-12-06T22:50:23.051Z,1701903023.051 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2023-12-06T22:50:23.054Z,1701903023.054 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2023-12-06T22:50:23.072Z,1701903023.072 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = nan ug/l
2023-12-06T22:50:23.091Z,1701903023.091 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = nan m
2023-12-06T22:50:23.094Z,1701903023.094 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2023-12-06T22:50:23.097Z,1701903023.097 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2023-12-06T22:50:23.121Z,1701903023.121 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2023-12-06T22:50:23.124Z,1701903023.124 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = nan psu
2023-12-06T22:50:23.140Z,1701903023.140 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = nan m
2023-12-06T22:50:23.144Z,1701903023.144 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2023-12-06T22:50:23.147Z,1701903023.147 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2023-12-06T22:50:23.162Z,1701903023.162 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2023-12-06T22:50:23.174Z,1701903023.174 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = nan psu
2023-12-06T22:50:23.181Z,1701903023.181 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = nan m
2023-12-06T22:50:23.201Z,1701903023.201 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2023-12-06T22:50:23.209Z,1701903023.209 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2023-12-06T22:50:23.228Z,1701903023.228 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2023-12-06T22:50:23.239Z,1701903023.239 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.TriggeredOnChl = 0 bool
2023-12-06T22:50:23.242Z,1701903023.242 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.ChlTriggering = nan ug/l
2023-12-06T22:50:23.387Z,1701903023.387 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-12-06T22:50:23.422Z,1701903023.422 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-12-06T22:50:23.481Z,1701903023.481 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-12-06T22:50:23.516Z,1701903023.516 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-12-06T22:50:23.546Z,1701903023.546 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-12-06T22:50:23.599Z,1701903023.599 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-12-06T22:50:23.665Z,1701903023.665 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-12-06T22:50:23.714Z,1701903023.714 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-12-06T22:50:23.766Z,1701903023.766 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Construct ValueDetect.
2023-12-06T22:50:23.802Z,1701903023.802 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2023-12-06T22:50:23.802Z,1701903023.802 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BackseatDriver.tx
2023-12-06T22:50:23.852Z,1701903023.852 [MissionManager](INFO): DefineArg ballast_and_trim:BackseatDriver.EnableBackseat = 0 bool
2023-12-06T22:50:24.433Z,1701903024.433 [ballast_and_trim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2023-12-06T22:50:24.461Z,1701903024.461 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.tl
2023-12-06T22:50:24.462Z,1701903024.462 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BallastAndTrim.tx
2023-12-06T22:50:24.817Z,1701903024.817 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2023-12-06T22:50:24.824Z,1701903024.824 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2023-12-06T22:50:24.840Z,1701903024.840 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2023-12-06T22:50:24.851Z,1701903024.851 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2023-12-06T22:50:24.854Z,1701903024.854 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2023-12-06T22:50:24.865Z,1701903024.865 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2023-12-06T22:50:24.874Z,1701903024.874 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2023-12-06T22:50:24.889Z,1701903024.889 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2023-12-06T22:50:24.896Z,1701903024.896 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2023-12-06T22:50:24.912Z,1701903024.912 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2023-12-06T22:50:24.921Z,1701903024.921 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2023-12-06T22:50:24.924Z,1701903024.924 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2023-12-06T22:50:24.967Z,1701903024.967 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2023-12-06T22:50:24.981Z,1701903024.981 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2023-12-06T22:50:25.014Z,1701903025.014 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2023-12-06T22:50:25.040Z,1701903025.040 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2023-12-06T22:50:25.044Z,1701903025.044 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2023-12-06T22:50:25.061Z,1701903025.061 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2023-12-06T22:50:25.087Z,1701903025.087 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2023-12-06T22:50:25.090Z,1701903025.090 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2023-12-06T22:50:25.117Z,1701903025.117 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2023-12-06T22:50:25.137Z,1701903025.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2023-12-06T22:50:25.140Z,1701903025.140 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2023-12-06T22:50:25.167Z,1701903025.167 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2023-12-06T22:50:25.169Z,1701903025.169 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute](DEBUG): Construct Execute.
2023-12-06T22:50:25.191Z,1701903025.191 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](DEBUG): Construct BallastAndTrim.
2023-12-06T22:50:25.243Z,1701903025.243 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2023-12-06T22:50:25.245Z,1701903025.245 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.TargetDepthTimeout
2023-12-06T22:50:25.246Z,1701903025.246 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2023-12-06T22:50:25.264Z,1701903025.264 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2023-12-06T22:50:25.266Z,1701903025.266 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2023-12-06T22:50:25.288Z,1701903025.288 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2023-12-06T22:50:25.290Z,1701903025.290 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2023-12-06T22:50:25.292Z,1701903025.292 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2023-12-06T22:50:25.340Z,1701903025.340 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2023-12-06T22:50:25.343Z,1701903025.343 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2023-12-06T22:50:25.467Z,1701903025.467 [MissionManager](DEBUG): 
mission ballast_and_trim {
  arguments {
    MissionTimeout = 120 minute
      """
      Maximum duration of mission.
      """

    Depth1 = 7 meter
      """
      Target depth for ballast and trim.
      """

    Depth2 = NaN meter
      """
      Target depth to run a second ballast and trim, skipped if NaN.
      """

    DepthDeadband = 0.1 meter
      """
      How much vertical drift from the specified depth is allowed during the
      mission.
      """

    SurfaceThreshold = 2.5 meter
      """
      Surface threshold depth, relevant only to the ascent.
      """

    TargetDepthTimeout = 20 minute
      """
      Maximum wait time for the vehicle to reach the target ballast and trim
      depth.
      """

    SettleTime = 10 minute
      """
      How long to wait after reaching target depth before starting ballast and
      trim.
      """

    EstimationTimeout = 45 minute
      """
      Timeout for ballast and trim estimation.
      """

    MinEstimationTime = 10 minute
      """
      Minimum time to run ballast and trim estimation before determining
      convergence (must be shorter than timeout).
      """

    MassEstimationErrorBound = 0.25 millimeter
      """
      Desired range of the estimated sample mean from the true mean statistic
      (smaller values take longer to converge).
      """

    BuoyEstimationErrorBound = 15 cubic_centimeter
      """
      Desired range of the estimated sample mean from the true mean statistic
      (smaller values take longer to converge).
      """

    EstimationConfidence = 99.9 percent
      """
      Confidence level that the estimator has reached the desired error range
      (larger values take longer to converge).
      """

    WaitToFloat = 5 minute
      """
      Timeout for reaching surface threshold on float ascent, mission will end
      when reached.
      """
  }

  timeout duration=MissionTimeout

  insert Insert/Science.tl

  insert Insert/BackseatDriver.tl

  aggregate RunBallastAndTrim {
    run in sequence

    insert Insert/BallastAndTrim.tl {
      redefineArg InsertDepthDeadband = DepthDeadband
      redefineArg InsertApproachDepthTimeout = TargetDepthTimeout
      redefineArg InsertSettleTime = SettleTime
      redefineArg EstTimeout = EstimationTimeout
      redefineArg MinEstTime = MinEstimationTime
      redefineArg MassEstErrorBound = MassEstimationErrorBound
      redefineArg BuoyEstErrorBound = BuoyEstimationErrorBound
      redefineArg EstConfidence = EstimationConfidence
    }

    aggregate Depth1 {
      run in sequence

      break if ( isNaN ( Depth1 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth1

      call refId="BallastAndTrim"
    }

    aggregate Depth2 {
      run in sequence

      break if ( isNaN ( Depth2 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth2

      call refId="BallastAndTrim"
    }
  }

  aggregate Float_Up {
    """
    Float to surface instead of driving.
    """

    run in sequence

    break if (
      Universal:depth < Control:VerticalControl.surfaceThreshold
    )

    behavior Guidance:Buoyancy {
      run in parallel

      set position = Control:VerticalControl.buoyancyDefault
    }

    behavior Guidance:Wait {
      run in sequence

      set duration = WaitToFloat
    }
  }
}


2023-12-06T22:50:25.479Z,1701903025.479 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-12-06T22:50:25.811Z,1701903025.811 [Default] Stopped
2023-12-06T22:50:25.811Z,1701903025.811 [Default](DEBUG): Aggregate::uninitialize Default
2023-12-06T22:50:25.811Z,1701903025.811 [Default:B.GoToSurface] Stopped
2023-12-06T22:50:25.811Z,1701903025.811 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-12-06T22:50:25.811Z,1701903025.811 [Default:CheckIn] Stopped
2023-12-06T22:50:25.812Z,1701903025.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-06T22:50:25.812Z,1701903025.812 [Default:CheckIn:C.Wait] Stopped
2023-12-06T22:50:25.812Z,1701903025.812 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T22:50:25.812Z,1701903025.812 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2023-12-06T22:50:25.812Z,1701903025.812 [ballast_and_trim] Running Loop=1
2023-12-06T22:50:25.812Z,1701903025.812 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2023-12-06T22:50:25.812Z,1701903025.812 [ballast_and_trim:Science] Running Loop=1
2023-12-06T22:50:25.812Z,1701903025.812 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2023-12-06T22:50:25.812Z,1701903025.812 [ballast_and_trim:Science:A] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:B] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:C] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:D] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:E] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:F] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2023-12-06T22:50:25.813Z,1701903025.813 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2023-12-06T22:50:25.824Z,1701903025.824 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2023-12-06T22:50:25.825Z,1701903025.825 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2023-12-06T22:50:25.825Z,1701903025.825 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-12-06T22:50:25.827Z,1701903025.827 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2023-12-06T22:50:25.827Z,1701903025.827 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2023-12-06T22:50:25.835Z,1701903025.835 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2023-12-06T22:50:25.835Z,1701903025.835 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-12-06T22:50:25.837Z,1701903025.837 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2023-12-06T22:50:25.837Z,1701903025.837 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2023-12-06T22:50:25.837Z,1701903025.837 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-12-06T22:50:25.838Z,1701903025.838 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-12-06T22:50:25.838Z,1701903025.838 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2023-12-06T22:50:25.838Z,1701903025.838 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2023-12-06T22:50:25.838Z,1701903025.838 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2023-12-06T22:50:25.838Z,1701903025.838 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-12-06T22:50:25.845Z,1701903025.845 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2023-12-06T22:50:25.845Z,1701903025.845 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2023-12-06T22:50:25.845Z,1701903025.845 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2023-12-06T22:50:25.845Z,1701903025.845 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-12-06T22:50:25.847Z,1701903025.847 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2023-12-06T22:50:25.847Z,1701903025.847 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2023-12-06T22:50:25.859Z,1701903025.859 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-12-06T22:50:25.859Z,1701903025.859 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-12-06T22:50:25.860Z,1701903025.860 [ballast_and_trim:Science:ChlThreshTrigger] Running Loop=1
2023-12-06T22:50:25.860Z,1701903025.860 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::initialize ballast_and_trim:Science:ChlThreshTrigger
2023-12-06T22:50:25.860Z,1701903025.860 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Running Loop=1
2023-12-06T22:50:25.860Z,1701903025.860 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](INFO): Initialize.
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:BackseatDriver] Running Loop=1
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::initialize ballast_and_trim:BackseatDriver
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Running Loop=1
2023-12-06T22:50:25.861Z,1701903025.861 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2023-12-06T22:50:25.862Z,1701903025.862 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2023-12-06T22:50:25.862Z,1701903025.862 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2023-12-06T22:50:25.862Z,1701903025.862 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-12-06T22:50:25.862Z,1701903025.862 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2023-12-06T22:50:25.862Z,1701903025.862 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2023-12-06T22:50:25.863Z,1701903025.863 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2023-12-06T22:50:25.863Z,1701903025.863 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-12-06T22:50:25.871Z,1701903025.871 [ballast_and_trim:BackseatDriver] Running Loop=1
2023-12-06T22:50:25.872Z,1701903025.872 [ballast_and_trim:Science] Running Loop=1
2023-12-06T22:50:25.872Z,1701903025.872 [ballast_and_trim:Science:ChlThreshTrigger] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:ChlThreshTrigger
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Uninitialize.
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-12-06T22:50:25.873Z,1701903025.873 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectOil] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-12-06T22:50:25.874Z,1701903025.874 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2023-12-06T22:50:25.875Z,1701903025.875 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2023-12-06T22:50:25.887Z,1701903025.887 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:PeakDetectChl] Stopped
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:Read_Oil] Stopped
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:F] Stopped
2023-12-06T22:50:25.888Z,1701903025.888 [ballast_and_trim:Science:E] Running Loop=1
2023-12-06T22:50:25.889Z,1701903025.889 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2023-12-06T22:50:25.889Z,1701903025.889 [ballast_and_trim:Science:D] Stopped
2023-12-06T22:50:25.889Z,1701903025.889 [ballast_and_trim:Science:C] Running Loop=1
2023-12-06T22:50:25.890Z,1701903025.890 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2023-12-06T22:50:25.890Z,1701903025.890 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2023-12-06T22:50:25.891Z,1701903025.891 [ballast_and_trim:Science:B] Running Loop=1
2023-12-06T22:50:25.897Z,1701903025.897 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2023-12-06T22:50:25.897Z,1701903025.897 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2023-12-06T22:50:25.897Z,1701903025.897 [ballast_and_trim:Science:A] Stopped
2023-12-06T22:50:26.209Z,1701903026.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2023-12-06T22:50:26.209Z,1701903026.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-12-06T22:50:26.209Z,1701903026.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-12-06T22:50:26.210Z,1701903026.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-12-06T22:50:26.210Z,1701903026.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-12-06T22:50:26.210Z,1701903026.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-12-06T22:50:26.210Z,1701903026.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-12-06T22:50:26.210Z,1701903026.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2023-12-06T22:50:26.212Z,1701903026.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2023-12-06T22:50:26.213Z,1701903026.213 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-12-06T22:50:26.214Z,1701903026.214 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-12-06T22:50:26.277Z,1701903026.277 [WetLabsBB2FL](INFO): Powering up
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-12-06T22:50:26.610Z,1701903026.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2023-12-06T22:50:26.611Z,1701903026.611 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2023-12-06T22:50:26.611Z,1701903026.611 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-12-06T22:50:26.611Z,1701903026.611 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2023-12-06T22:50:26.611Z,1701903026.611 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2023-12-06T22:50:27.024Z,1701903027.024 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-12-06T22:50:27.025Z,1701903027.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2023-12-06T22:50:27.025Z,1701903027.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-12-06T22:50:27.025Z,1701903027.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-12-06T22:50:27.025Z,1701903027.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2023-12-06T22:50:27.025Z,1701903027.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2023-12-06T22:50:27.411Z,1701903027.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-12-06T22:50:27.412Z,1701903027.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2023-12-06T22:50:27.412Z,1701903027.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2023-12-06T22:50:27.412Z,1701903027.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2023-12-06T22:50:27.412Z,1701903027.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2023-12-06T22:50:28.984Z,1701903028.984 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2023-12-06T22:50:30.993Z,1701903030.993 [CTD_Seabird](ERROR): Salinity reading out of range: 2.529548 psu
2023-12-06T22:50:30.996Z,1701903030.996 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T22:51:45.063Z,1701903105.063 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-12-06T22:52:16.187Z,1701903136.187 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T22:52:35.327Z,1701903155.327 [Radio_Surface](INFO): Powering down
2023-12-06T22:52:47.312Z,1701903167.312 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T22:52:48.316Z,1701903168.316 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-12-06T22:53:28.459Z,1701903208.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2023-12-06T22:53:28.460Z,1701903208.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-12-06T22:53:28.460Z,1701903208.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2023-12-06T22:53:28.460Z,1701903208.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-12-06T22:53:28.460Z,1701903208.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2023-12-06T22:53:28.460Z,1701903208.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-12-06T22:53:28.461Z,1701903208.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2023-12-06T22:53:28.462Z,1701903208.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2023-12-06T22:53:28.868Z,1701903208.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.051120 m 
2023-12-06T22:53:28.868Z,1701903208.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2023-12-06T22:53:28.869Z,1701903208.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2023-12-06T22:53:28.869Z,1701903208.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2023-12-06T22:53:28.869Z,1701903208.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-12-06T22:53:28.869Z,1701903208.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-12-06T22:53:56.603Z,1701903236.603 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.851151
2023-12-06T23:03:29.648Z,1701903809.648 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2023-12-06T23:03:29.648Z,1701903809.648 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2023-12-06T23:03:29.648Z,1701903809.648 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:03:29.649Z,1701903809.649 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute] Running Loop=1
2023-12-06T23:03:30.063Z,1701903810.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute](INFO): Executing command gfscan
2023-12-06T23:03:30.063Z,1701903810.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute] Stopped
2023-12-06T23:03:30.063Z,1701903810.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F] Running Loop=1
2023-12-06T23:03:30.096Z,1701903810.096 [CommandExec](IMPORTANT): got command gfscan
2023-12-06T23:03:30.457Z,1701903810.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F](INFO): Running ballast and trim. Depth = 6.567595 m 
2023-12-06T23:03:30.457Z,1701903810.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F] Stopped
2023-12-06T23:03:30.457Z,1701903810.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.] Running Loop=1
2023-12-06T23:03:30.457Z,1701903810.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](INFO): Initializing BallastAndTrim.
2023-12-06T23:03:30.632Z,1701903810.632 [CBIT](IMPORTANT): Beginning ground fault scan
2023-12-06T23:03:31.245Z,1701903811.245 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:31.247Z,1701903811.247 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:32.249Z,1701903812.249 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:32.250Z,1701903812.250 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:33.253Z,1701903813.253 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:33.254Z,1701903813.254 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:33.324Z,1701903813.324 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-12-06T23:03:34.257Z,1701903814.257 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:34.258Z,1701903814.258 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:35.261Z,1701903815.261 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:35.262Z,1701903815.262 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:36.270Z,1701903816.270 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:36.271Z,1701903816.271 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:37.269Z,1701903817.269 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:37.270Z,1701903817.270 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:38.275Z,1701903818.275 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:38.277Z,1701903818.277 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:39.277Z,1701903819.277 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:39.278Z,1701903819.278 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:40.281Z,1701903820.281 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:40.282Z,1701903820.282 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:41.285Z,1701903821.285 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2023-12-06T23:03:41.286Z,1701903821.286 [CTD_Seabird](INFO): some bad data, not updating bins
2023-12-06T23:03:41.387Z,1701903821.387 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002290
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.002403
CHAN A3 (5V): -0.001494
CHAN B0 (3.3V): -0.000137
CHAN B1 (3.15aV): -0.000011
CHAN B2 (3.15bV): -0.000152
CHAN B3 (GND): 0.000293
OPEN: -0.000471
Full Scale: +/- 1 mA
2023-12-06T23:29:11.751Z,1701905351.751 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): BallastAndTrim completed. Estimation time: 25.68 minutes.
2023-12-06T23:29:11.752Z,1701905351.752 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Estimated buoyancyNeutral: 255.186074 +/- 14.998216 cc (conf. level 99.90%, sigma: 28.460882 cc).
2023-12-06T23:29:11.753Z,1701905351.753 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Estimated massDefault: -11.847765 +/- 0.184173 mm (conf. level 99.90%, sigma: 0.349490 mm).
2023-12-06T23:29:11.754Z,1701905351.754 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Changing persisted config values to: 255.186074 cc buoyancy neutral and -11.847765 mm mass default
2023-12-06T23:29:11.759Z,1701905351.759 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-12-06T23:29:11.776Z,1701905351.776 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): ThrusterServo.currLimit=50 percent;

2023-12-06T23:29:11.777Z,1701905351.777 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): VerticalControl.buoyancyNeutral=255.186074 cubic_centimeter;

2023-12-06T23:29:11.777Z,1701905351.777 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): VerticalControl.massDefault=-11.847765 millimeter;

2023-12-06T23:29:11.777Z,1701905351.777 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.] Stopped
2023-12-06T23:29:11.777Z,1701905351.777 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](INFO): Uninitializing BallastAndTrim.
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2023-12-06T23:29:11.778Z,1701905351.778 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2023-12-06T23:29:11.785Z,1701905351.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-12-06T23:29:12.209Z,1701905352.209 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2023-12-06T23:29:12.210Z,1701905352.210 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-12-06T23:29:12.210Z,1701905352.210 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim] Stopped
2023-12-06T23:29:12.576Z,1701905352.576 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up] Running Loop=1
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2023-12-06T23:29:12.577Z,1701905352.577 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:29:12.963Z,1701905352.963 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up] Stopped
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up:B.Wait] Stopped
2023-12-06T23:31:14.178Z,1701905474.178 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:31:14.180Z,1701905474.180 [ballast_and_trim](INFO): Completed ballast_and_trim
2023-12-06T23:31:14.180Z,1701905474.180 [MissionManager](INFO): ballast_and_trim is completed.
2023-12-06T23:31:14.181Z,1701905474.181 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:B] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:C] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:E] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:OceanCurrent] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2023-12-06T23:31:14.181Z,1701905474.181 [ballast_and_trim:BackseatDriver] Stopped
2023-12-06T23:31:14.182Z,1701905474.182 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::uninitialize ballast_and_trim:BackseatDriver
2023-12-06T23:31:14.182Z,1701905474.182 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Stopped
2023-12-06T23:31:14.579Z,1701905474.579 [MissionManager](IMPORTANT): Started mission Default
2023-12-06T23:31:14.579Z,1701905474.579 [Default] Running Loop=1
2023-12-06T23:31:14.579Z,1701905474.579 [Default](DEBUG): Aggregate::initialize Default
2023-12-06T23:31:14.579Z,1701905474.579 [Default:B.GoToSurface] Running Loop=1
2023-12-06T23:31:14.579Z,1701905474.579 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-06T23:31:14.580Z,1701905474.580 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-06T23:31:14.580Z,1701905474.580 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-06T23:31:14.580Z,1701905474.580 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-06T23:31:14.581Z,1701905474.581 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-06T23:31:14.581Z,1701905474.581 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-06T23:31:14.581Z,1701905474.581 [Default:A.Wait] Running Loop=1
2023-12-06T23:31:14.581Z,1701905474.581 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:31:14.703Z,1701905474.703 [WetLabsBB2FL](INFO): Powering down
2023-12-06T23:31:14.819Z,1701905474.819 [Radio_Surface](INFO): Powering up
2023-12-06T23:31:20.907Z,1701905480.907 [DataOverHttps](INFO): Radio surface powered ON.
2023-12-06T23:31:27.903Z,1701905487.903 [Default:A.Wait](INFO): Done Waiting.
2023-12-06T23:31:27.903Z,1701905487.903 [Default:A.Wait] Stopped
2023-12-06T23:31:27.903Z,1701905487.903 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:31:28.312Z,1701905488.312 [Default:CheckIn] Running Loop=1
2023-12-06T23:31:28.313Z,1701905488.313 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T23:31:28.313Z,1701905488.313 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T23:31:51.027Z,1701905511.027 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:32:22.151Z,1701905542.151 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:32:53.275Z,1701905573.275 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:33:24.399Z,1701905604.399 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:33:55.523Z,1701905635.523 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:34:26.647Z,1701905666.647 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-12-06T23:34:58.995Z,1701905698.995 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003147
2023-12-06T23:36:28.513Z,1701905788.513 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-06T23:31:28.3Z
2023-12-06T23:36:28.513Z,1701905788.513 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T23:36:28.513Z,1701905788.513 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T23:36:32.714Z,1701905792.714 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-06T23:36:36.658Z,1701905796.658 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231206T222907/Courier0010.lzma
2023-12-06T23:36:37.661Z,1701905797.661 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0010.lzma.bak
2023-12-06T23:36:37.661Z,1701905797.661 [DataOverHttps](INFO): SBD MOMSN=19091489
2023-12-06T23:36:56.485Z,1701905816.485 [DataOverHttps](INFO): Sending 1368 bytes from file Logs/20231206T222907/Express0011.lzma
2023-12-06T23:36:57.485Z,1701905817.485 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0011.lzma.bak
2023-12-06T23:36:57.485Z,1701905817.485 [DataOverHttps](INFO): SBD MOMSN=19091491
2023-12-06T23:37:03.300Z,1701905823.300 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-06T23:37:13.455Z,1701905833.455 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20231206T222907/Express0014.lzma
2023-12-06T23:37:14.457Z,1701905834.457 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0014.lzma.bak
2023-12-06T23:37:14.457Z,1701905834.457 [DataOverHttps](INFO): SBD MOMSN=19091519
2023-12-06T23:37:15.840Z,1701905835.840 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T23:37:15.840Z,1701905835.840 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T23:37:15.840Z,1701905835.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:39:15.410Z,1701905955.410 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 6.
2023-12-06T23:39:15.413Z,1701905955.413 [BPC1](INFO): Received data from all battery sticks.
2023-12-06T23:42:16.423Z,1701906136.423 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-06T23:42:16.423Z,1701906136.423 [Default:CheckIn:C.Wait] Stopped
2023-12-06T23:42:16.423Z,1701906136.423 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:42:16.423Z,1701906136.423 [Default:CheckIn:D] Running Loop=1
2023-12-06T23:42:16.837Z,1701906136.837 [Default:CheckIn:D] Stopped
2023-12-06T23:42:16.837Z,1701906136.837 [Default:CheckIn:E] Running Loop=1
2023-12-06T23:42:17.225Z,1701906137.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.037627 min 
2023-12-06T23:42:17.225Z,1701906137.225 [Default:CheckIn:E] Stopped
2023-12-06T23:42:17.225Z,1701906137.225 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-06T23:42:17.225Z,1701906137.225 [Default:CheckIn] Stopped
2023-12-06T23:42:17.226Z,1701906137.226 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-06T23:42:17.226Z,1701906137.226 [Default:CheckIn](INFO): Running loop #2
2023-12-06T23:42:17.226Z,1701906137.226 [Default:CheckIn] Running Loop=2
2023-12-06T23:42:17.226Z,1701906137.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T23:42:17.226Z,1701906137.226 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T23:42:18.833Z,1701906138.833 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-12-06T23:42:18.833Z,1701906138.833 [NAL9602] Data Fault, FailCount= 2
2023-12-06T23:42:18.833Z,1701906138.833 [NAL9602](ERROR): Data Fault
2023-12-06T23:42:18.885Z,1701906138.885 [CBIT](ERROR): Data Fault in component: NAL9602
2023-12-06T23:42:19.240Z,1701906139.240 [NAL9602](INFO): Powering down
2023-12-06T23:42:20.077Z,1701906140.077 [CBIT](INFO): Clearing failed state for component NAL9602
2023-12-06T23:42:20.077Z,1701906140.077 [NAL9602] No Fault, FailCount= 2
2023-12-06T23:42:49.664Z,1701906169.664 [NAL9602](INFO): Powering up NAL9602
2023-12-06T23:43:00.851Z,1701906180.851 [NAL9602](INFO): NAL9602 initialized
2023-12-06T23:47:17.419Z,1701906437.419 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-06T23:42:17.2Z
2023-12-06T23:47:17.419Z,1701906437.419 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T23:47:17.420Z,1701906437.420 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T23:47:24.990Z,1701906444.990 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20231206T222907/Courier0016.lzma
2023-12-06T23:47:25.993Z,1701906445.993 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0016.lzma.bak
2023-12-06T23:47:25.993Z,1701906445.993 [DataOverHttps](INFO): SBD MOMSN=19091526
2023-12-06T23:47:41.903Z,1701906461.903 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20231206T222907/Express0017.lzma
2023-12-06T23:47:42.917Z,1701906462.917 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0017.lzma.bak
2023-12-06T23:47:42.917Z,1701906462.917 [DataOverHttps](INFO): SBD MOMSN=19091528
2023-12-06T23:47:44.080Z,1701906464.080 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T23:47:44.080Z,1701906464.080 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T23:47:44.080Z,1701906464.080 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:48:04.272Z,1701906484.272 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-06T23:48:34.976Z,1701906514.976 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-06T23:52:44.859Z,1701906764.859 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-06T23:52:44.859Z,1701906764.859 [Default:CheckIn:C.Wait] Stopped
2023-12-06T23:52:44.859Z,1701906764.859 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:52:44.860Z,1701906764.860 [Default:CheckIn:D] Running Loop=1
2023-12-06T23:52:45.214Z,1701906765.214 [Default:CheckIn:D] Stopped
2023-12-06T23:52:45.215Z,1701906765.215 [Default:CheckIn:E] Running Loop=1
2023-12-06T23:52:45.627Z,1701906765.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.510590 min 
2023-12-06T23:52:45.627Z,1701906765.627 [Default:CheckIn:E] Stopped
2023-12-06T23:52:45.627Z,1701906765.627 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-06T23:52:45.627Z,1701906765.627 [Default:CheckIn] Stopped
2023-12-06T23:52:45.627Z,1701906765.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-06T23:52:45.628Z,1701906765.628 [Default:CheckIn](INFO): Running loop #3
2023-12-06T23:52:45.628Z,1701906765.628 [Default:CheckIn] Running Loop=3
2023-12-06T23:52:45.628Z,1701906765.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T23:52:45.628Z,1701906765.628 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T23:52:47.626Z,1701906767.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235249.00,A,3648.16197,N,12147.28744,W,0.525,345.60,061223,,,A*78
2023-12-06T23:52:47.628Z,1701906767.628 [NAL9602](INFO): GPS fix at 20231206T235249: (36.802700, -121.788124)
2023-12-06T23:52:47.648Z,1701906767.648 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T23:52:47.648Z,1701906767.648 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T23:52:57.490Z,1701906777.490 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231206T222907/Courier0019.lzma
2023-12-06T23:52:58.493Z,1701906778.493 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0019.lzma.bak
2023-12-06T23:52:58.493Z,1701906778.493 [DataOverHttps](INFO): SBD MOMSN=19091574
2023-12-06T23:53:14.250Z,1701906794.250 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20231206T222907/Express0020.lzma
2023-12-06T23:53:15.249Z,1701906795.249 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0020.lzma.bak
2023-12-06T23:53:15.249Z,1701906795.249 [DataOverHttps](INFO): SBD MOMSN=19091577
2023-12-06T23:53:16.370Z,1701906796.370 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T23:53:16.370Z,1701906796.370 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T23:53:16.370Z,1701906796.370 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:53:18.368Z,1701906798.368 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-12-06T23:53:18.443Z,1701906798.443 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-12-06T23:57:49.944Z,1701907069.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-06T23:58:17.031Z,1701907097.031 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-06T23:58:17.031Z,1701907097.031 [Default:CheckIn:C.Wait] Stopped
2023-12-06T23:58:17.031Z,1701907097.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-06T23:58:17.031Z,1701907097.031 [Default:CheckIn:D] Running Loop=1
2023-12-06T23:58:17.424Z,1701907097.424 [Default:CheckIn:D] Stopped
2023-12-06T23:58:17.424Z,1701907097.424 [Default:CheckIn:E] Running Loop=1
2023-12-06T23:58:17.831Z,1701907097.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.047420 min 
2023-12-06T23:58:17.831Z,1701907097.831 [Default:CheckIn:E] Stopped
2023-12-06T23:58:17.831Z,1701907097.831 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-06T23:58:17.831Z,1701907097.831 [Default:CheckIn] Stopped
2023-12-06T23:58:17.832Z,1701907097.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-06T23:58:17.832Z,1701907097.832 [Default:CheckIn](INFO): Running loop #4
2023-12-06T23:58:17.832Z,1701907097.832 [Default:CheckIn] Running Loop=4
2023-12-06T23:58:17.832Z,1701907097.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-06T23:58:17.832Z,1701907097.832 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-06T23:58:19.838Z,1701907099.838 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235821.00,A,3648.16774,N,12147.27969,W,1.244,220.89,061223,,,A*7D
2023-12-06T23:58:19.841Z,1701907099.841 [NAL9602](INFO): GPS fix at 20231206T235821: (36.802796, -121.787995)
2023-12-06T23:58:19.852Z,1701907099.852 [Default:CheckIn:Read_GPS] Stopped
2023-12-06T23:58:19.852Z,1701907099.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-06T23:58:27.506Z,1701907107.506 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231206T222907/Courier0022.lzma
2023-12-06T23:58:28.509Z,1701907108.509 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0022.lzma.bak
2023-12-06T23:58:28.509Z,1701907108.509 [DataOverHttps](INFO): SBD MOMSN=19091590
2023-12-06T23:58:44.397Z,1701907124.397 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231206T222907/Express0023.lzma
2023-12-06T23:58:45.397Z,1701907125.397 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0023.lzma.bak
2023-12-06T23:58:45.397Z,1701907125.397 [DataOverHttps](INFO): SBD MOMSN=19091593
2023-12-06T23:58:46.564Z,1701907126.564 [Default:CheckIn:Read_Iridium] Stopped
2023-12-06T23:58:46.564Z,1701907126.564 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-06T23:58:46.564Z,1701907126.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-06T23:58:51.818Z,1701907131.818 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-06T23:59:22.528Z,1701907162.528 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2023-12-06T23:59:22.528Z,1701907162.528 [DropWeight] Hardware Fault, FailCount= 1
2023-12-06T23:59:22.528Z,1701907162.528 [DropWeight](ERROR): Hardware Fault
2023-12-06T23:59:22.576Z,1701907162.576 [CommandExec](FAULT): Scheduling is paused
2023-12-06T23:59:22.576Z,1701907162.576 [CBIT](INFO): Critical error at 20231206T235922
2023-12-06T23:59:22.576Z,1701907162.576 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-12-06T23:59:22.584Z,1701907162.584 [CBIT](ERROR): Hardware Fault in component: DropWeight
2023-12-06T23:59:22.584Z,1701907162.584 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2023-12-06T23:59:22.972Z,1701907162.972 [CBIT](INFO): Critical error at 20231206T235922
2023-12-07T00:03:47.174Z,1701907427.174 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-07T00:03:47.174Z,1701907427.174 [Default:CheckIn:C.Wait] Stopped
2023-12-07T00:03:47.174Z,1701907427.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-07T00:03:47.174Z,1701907427.174 [Default:CheckIn:D] Running Loop=1
2023-12-07T00:03:47.600Z,1701907427.600 [Default:CheckIn:D] Stopped
2023-12-07T00:03:47.600Z,1701907427.600 [Default:CheckIn:E] Running Loop=1
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.550344 min 
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn:E] Stopped
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn] Stopped
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn](INFO): Running loop #5
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn] Running Loop=5
2023-12-07T00:03:47.982Z,1701907427.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-07T00:03:47.983Z,1701907427.983 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-07T00:03:49.998Z,1701907429.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000351.00,A,3648.16497,N,12147.28186,W,0.544,208.35,071223,,,A*77
2023-12-07T00:03:50.005Z,1701907430.005 [NAL9602](INFO): GPS fix at 20231207T000351: (36.802749, -121.788031)
2023-12-07T00:03:50.016Z,1701907430.016 [Default:CheckIn:Read_GPS] Stopped
2023-12-07T00:03:50.016Z,1701907430.016 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-07T00:03:57.883Z,1701907437.883 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20231206T222907/Courier0025.lzma
2023-12-07T00:03:58.885Z,1701907438.885 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0025.lzma.bak
2023-12-07T00:03:58.885Z,1701907438.885 [DataOverHttps](INFO): SBD MOMSN=19091601
2023-12-07T00:04:14.829Z,1701907454.829 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20231206T222907/Express0026.lzma
2023-12-07T00:04:15.721Z,1701907455.721 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0026.lzma.bak
2023-12-07T00:04:15.721Z,1701907455.721 [DataOverHttps](INFO): SBD MOMSN=19091606
2023-12-07T00:04:17.072Z,1701907457.072 [Default:CheckIn:Read_Iridium] Stopped
2023-12-07T00:04:17.072Z,1701907457.072 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-07T00:04:17.072Z,1701907457.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-07T00:04:20.696Z,1701907460.696 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-12-07T00:04:20.779Z,1701907460.779 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-12-07T00:05:26.590Z,1701907526.590 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0
2023-12-07T00:05:26.590Z,1701907526.590 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-12-07T00:06:01.333Z,1701907561.333 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0
2023-12-07T00:06:01.334Z,1701907561.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-12-07T00:08:52.592Z,1701907732.592 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-07T00:09:17.659Z,1701907757.659 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-07T00:09:17.659Z,1701907757.659 [Default:CheckIn:C.Wait] Stopped
2023-12-07T00:09:17.659Z,1701907757.659 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-07T00:09:17.660Z,1701907757.660 [Default:CheckIn:D] Running Loop=1
2023-12-07T00:09:18.067Z,1701907758.067 [Default:CheckIn:D] Stopped
2023-12-07T00:09:18.067Z,1701907758.067 [Default:CheckIn:E] Running Loop=1
2023-12-07T00:09:18.470Z,1701907758.470 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.058126 min 
2023-12-07T00:09:18.470Z,1701907758.470 [Default:CheckIn:E] Stopped
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn] Stopped
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn](INFO): Running loop #6
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn] Running Loop=6
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-07T00:09:18.471Z,1701907758.471 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-07T00:09:20.479Z,1701907760.479 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000919.00,A,3648.18568,N,12147.28667,W,2.916,339.88,071223,,,A*7A
2023-12-07T00:09:20.481Z,1701907760.481 [NAL9602](INFO): GPS fix at 20231207T000919: (36.803095, -121.788111)
2023-12-07T00:09:20.516Z,1701907760.516 [Default:CheckIn:Read_GPS] Stopped
2023-12-07T00:09:20.516Z,1701907760.516 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-07T00:09:28.187Z,1701907768.187 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231206T222907/Courier0028.lzma
2023-12-07T00:09:29.190Z,1701907769.190 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0028.lzma.bak
2023-12-07T00:09:29.190Z,1701907769.190 [DataOverHttps](INFO): SBD MOMSN=19091616
2023-12-07T00:09:45.068Z,1701907785.068 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20231206T222907/Express0029.lzma
2023-12-07T00:09:46.070Z,1701907786.070 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0029.lzma.bak
2023-12-07T00:09:46.070Z,1701907786.070 [DataOverHttps](INFO): SBD MOMSN=19091624
2023-12-07T00:09:47.566Z,1701907787.566 [Default:CheckIn:Read_Iridium] Stopped
2023-12-07T00:09:47.566Z,1701907787.566 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-07T00:09:47.566Z,1701907787.566 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-07T00:09:53.220Z,1701907793.220 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-07T00:14:22.701Z,1701908062.701 [CBIT](INFO): Clearing failed state for component DropWeight
2023-12-07T00:14:22.701Z,1701908062.701 [DropWeight] No Fault, FailCount= 1
2023-12-07T00:14:48.155Z,1701908088.155 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-07T00:14:48.155Z,1701908088.155 [Default:CheckIn:C.Wait] Stopped
2023-12-07T00:14:48.155Z,1701908088.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-07T00:14:48.156Z,1701908088.156 [Default:CheckIn:D] Running Loop=1
2023-12-07T00:14:48.551Z,1701908088.551 [Default:CheckIn:D] Stopped
2023-12-07T00:14:48.551Z,1701908088.551 [Default:CheckIn:E] Running Loop=1
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.566195 min 
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn:E] Stopped
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn] Stopped
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-07T00:14:48.959Z,1701908088.959 [Default:CheckIn](INFO): Running loop #7
2023-12-07T00:14:48.960Z,1701908088.960 [Default:CheckIn] Running Loop=7
2023-12-07T00:14:48.960Z,1701908088.960 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-07T00:14:48.960Z,1701908088.960 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-07T00:15:21.670Z,1701908121.670 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-12-07T00:15:21.748Z,1701908121.748 [NAL9602](ERROR): received: 
+CSQ:0

OK817, 2, 0, 0, 0

OK
2023-12-07T00:19:48.983Z,1701908388.983 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-07T00:14:48.0Z
2023-12-07T00:19:48.983Z,1701908388.983 [Default:CheckIn:Read_GPS] Stopped
2023-12-07T00:19:48.984Z,1701908388.984 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-07T00:19:53.004Z,1701908393.004 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-07T00:19:56.730Z,1701908396.730 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231206T222907/Courier0031.lzma
2023-12-07T00:19:57.732Z,1701908397.732 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0031.lzma.bak
2023-12-07T00:19:57.733Z,1701908397.733 [DataOverHttps](INFO): SBD MOMSN=19091641
2023-12-07T00:20:16.794Z,1701908416.794 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20231206T222907/Express0032.lzma
2023-12-07T00:20:17.797Z,1701908417.797 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0032.lzma.bak
2023-12-07T00:20:17.797Z,1701908417.797 [DataOverHttps](INFO): SBD MOMSN=19091643
2023-12-07T00:20:18.945Z,1701908418.945 [Default:CheckIn:Read_Iridium] Stopped
2023-12-07T00:20:18.945Z,1701908418.945 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-07T00:20:18.946Z,1701908418.946 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-07T00:20:23.784Z,1701908423.784 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-07T00:25:19.550Z,1701908719.550 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-12-07T00:25:19.550Z,1701908719.550 [Default:CheckIn:C.Wait] Stopped
2023-12-07T00:25:19.550Z,1701908719.550 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-07T00:25:19.551Z,1701908719.551 [Default:CheckIn:D] Running Loop=1
2023-12-07T00:25:19.951Z,1701908719.951 [Default:CheckIn:D] Stopped
2023-12-07T00:25:19.951Z,1701908719.951 [Default:CheckIn:E] Running Loop=1
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.089535 min 
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn:E] Stopped
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn] Stopped
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn](INFO): Running loop #8
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn] Running Loop=8
2023-12-07T00:25:20.364Z,1701908720.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-07T00:25:20.365Z,1701908720.365 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-07T00:25:21.964Z,1701908721.964 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-12-07T00:25:21.964Z,1701908721.964 [NAL9602] Data Fault, FailCount= 3
2023-12-07T00:25:21.964Z,1701908721.964 [NAL9602](ERROR): Data Fault
2023-12-07T00:25:22.013Z,1701908722.013 [CBIT](ERROR): Data Fault in component: NAL9602
2023-12-07T00:25:22.368Z,1701908722.368 [NAL9602](INFO): Powering down
2023-12-07T00:25:23.199Z,1701908723.199 [CBIT](INFO): Clearing failed state for component NAL9602
2023-12-07T00:25:23.199Z,1701908723.199 [NAL9602] No Fault, FailCount= 3
2023-12-07T00:25:52.668Z,1701908752.668 [NAL9602](INFO): Powering up NAL9602
2023-12-07T00:26:03.571Z,1701908763.571 [NAL9602](INFO): NAL9602 initialized
2023-12-07T00:30:20.538Z,1701909020.538 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-07T00:25:20.4Z
2023-12-07T00:30:20.538Z,1701909020.538 [Default:CheckIn:Read_GPS] Stopped
2023-12-07T00:30:20.543Z,1701909020.543 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-07T00:30:28.250Z,1701909028.250 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231206T222907/Courier0034.lzma
2023-12-07T00:30:29.252Z,1701909029.252 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Courier0034.lzma.bak
2023-12-07T00:30:29.253Z,1701909029.253 [DataOverHttps](INFO): SBD MOMSN=19091650
2023-12-07T00:30:45.100Z,1701909045.100 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20231206T222907/Express0035.lzma
2023-12-07T00:30:46.101Z,1701909046.101 [DataOverHttps](INFO): Moved sent file to Logs/20231206T222907/Express0035.lzma.bak
2023-12-07T00:30:46.101Z,1701909046.101 [DataOverHttps](INFO): SBD MOMSN=19091653
2023-12-07T00:30:47.206Z,1701909047.206 [Default:CheckIn:Read_Iridium] Stopped
2023-12-07T00:30:47.206Z,1701909047.206 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-07T00:30:47.206Z,1701909047.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-07T00:31:06.988Z,1701909066.988 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-07T00:31:37.687Z,1701909097.687 [NAL9602](INFO): Not Powering down - fast GPS
2023-12-07T00:32:29.938Z,1701909149.938 [CommandExec](IMPORTANT): got command restart system
2023-12-07T00:32:32.029Z,1701909152.029 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-12-07T00:32:32.029Z,1701909152.029 [CommandExec](INFO): Uninitializing the command executive.
2023-12-07T00:32:32.029Z,1701909152.029 [CommandExec](INFO): Uninitializing the command scheduler.
2023-12-07T00:32:32.030Z,1701909152.030 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.117Z,1701909152.117 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-12-07T00:32:32.117Z,1701909152.117 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-12-07T00:32:32.118Z,1701909152.118 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.119Z,1701909152.119 [NavChartDb](INFO): Join timeout helper Thread ID is 1979
2023-12-07T00:32:32.249Z,1701909152.249 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-12-07T00:32:32.249Z,1701909152.249 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.274Z,1701909152.274 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-12-07T00:32:32.274Z,1701909152.274 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.275Z,1701909152.275 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1980
2023-12-07T00:32:32.558Z,1701909152.558 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-12-07T00:32:32.559Z,1701909152.559 [WetLabsBB2FL](INFO): Powering down
2023-12-07T00:32:32.560Z,1701909152.560 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.565Z,1701909152.565 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-12-07T00:32:32.565Z,1701909152.565 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-12-07T00:32:32.565Z,1701909152.565 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1981
2023-12-07T00:32:33.181Z,1701909153.181 [CTD_Seabird](INFO): Powering down
2023-12-07T00:32:33.193Z,1701909153.193 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-12-07T00:32:33.193Z,1701909153.193 [CTD_Seabird](INFO): Powering down
2023-12-0