2022-12-14T17:56:59.797Z,1671040619.797 [Supervisor](DEBUG): Initializing supervisor.
2022-12-14T17:56:59.846Z,1671040619.846 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-12-14T17:56:59.846Z,1671040619.846 [SyncHandler](INFO): Protected caller Thread ID is 8867
2022-12-14T17:56:59.847Z,1671040619.847 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-12-14T17:56:59.848Z,1671040619.848 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-12-14T17:56:59.848Z,1671040619.848 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8868
2022-12-14T17:56:59.852Z,1671040619.852 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-12-14T17:56:59.874Z,1671040619.874 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-12-14T17:56:59.875Z,1671040619.875 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-12-14T17:56:59.876Z,1671040619.876 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8869
2022-12-14T17:56:59.881Z,1671040619.881 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-12-14T17:56:59.882Z,1671040619.882 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-12-14T17:56:59.882Z,1671040619.882 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8870
2022-12-14T17:56:59.884Z,1671040619.884 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-12-14T17:56:59.885Z,1671040619.885 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-12-14T17:56:59.885Z,1671040619.885 [logger ThreadHandler](INFO): Protected caller Thread ID is 8871
2022-12-14T17:56:59.889Z,1671040619.889 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-12-14T17:56:59.889Z,1671040619.889 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-12-14T17:56:59.894Z,1671040619.894 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-12-14T17:57:00.412Z,1671040620.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-12-14T17:57:00.414Z,1671040620.414 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-12-14T17:57:00.616Z,1671040620.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-12-14T17:57:00.618Z,1671040620.618 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-12-14T17:57:00.698Z,1671040620.698 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-12-14T17:57:00.920Z,1671040620.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-12-14T17:57:00.922Z,1671040620.922 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-12-14T17:57:01.001Z,1671040621.001 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-12-14T17:57:01.095Z,1671040621.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-12-14T17:57:01.097Z,1671040621.097 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-12-14T17:57:01.435Z,1671040621.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-12-14T17:57:01.437Z,1671040621.437 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-12-14T17:57:01.565Z,1671040621.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-12-14T17:57:01.567Z,1671040621.567 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-12-14T17:57:02.038Z,1671040622.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-12-14T17:57:02.040Z,1671040622.040 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-12-14T17:57:02.230Z,1671040622.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-12-14T17:57:02.232Z,1671040622.232 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-12-14T17:57:02.640Z,1671040622.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-12-14T17:57:02.641Z,1671040622.641 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-12-14T17:57:02.998Z,1671040622.998 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-12-14T17:57:03.000Z,1671040623.000 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-12-14T17:57:03.108Z,1671040623.108 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-12-14T17:57:03.110Z,1671040623.110 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-12-14T17:57:04.212Z,1671040624.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-12-14T17:57:04.213Z,1671040624.213 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-12-14T17:57:04.535Z,1671040624.535 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-12-14T17:57:04.537Z,1671040624.537 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-12-14T17:57:04.749Z,1671040624.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-12-14T17:57:04.751Z,1671040624.751 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2022-12-14T17:57:04.755Z,1671040624.755 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2022-12-14T17:57:04.936Z,1671040624.936 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2022-12-14T17:57:05.018Z,1671040625.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2022-12-14T17:57:05.149Z,1671040625.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2022-12-14T17:57:05.233Z,1671040625.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2022-12-14T17:57:05.494Z,1671040625.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-12-14T17:57:05.494Z,1671040625.494 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2022-12-14T17:57:05.595Z,1671040625.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2022-12-14T17:57:05.703Z,1671040625.703 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2022-12-14T17:57:05.812Z,1671040625.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2022-12-14T17:57:05.950Z,1671040625.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2022-12-14T17:57:06.047Z,1671040626.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2022-12-14T17:57:06.143Z,1671040626.143 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2022-12-14T17:57:06.144Z,1671040626.144 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-12-14T17:57:06.158Z,1671040626.158 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-12-14T17:57:06.175Z,1671040626.175 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-12-14T17:57:06.175Z,1671040626.175 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-12-14T17:57:06.301Z,1671040626.301 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-12-14T17:57:06.302Z,1671040626.302 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-12-14T17:57:06.370Z,1671040626.370 [VerticalControl](DEBUG): Construct VerticalControl.
2022-12-14T17:57:06.430Z,1671040626.430 [VerticalControl] Loaded
2022-12-14T17:57:06.431Z,1671040626.431 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-12-14T17:57:06.433Z,1671040626.433 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-12-14T17:57:06.474Z,1671040626.474 [HorizontalControl] Loaded
2022-12-14T17:57:06.475Z,1671040626.475 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-12-14T17:57:06.477Z,1671040626.477 [SpeedControl](DEBUG): Construct SpeedControl.
2022-12-14T17:57:06.480Z,1671040626.480 [SpeedControl] Loaded
2022-12-14T17:57:06.480Z,1671040626.480 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-12-14T17:57:06.483Z,1671040626.483 [LoopControl](DEBUG): Construct LoopControl.
2022-12-14T17:57:06.484Z,1671040626.484 [LoopControl] Loaded
2022-12-14T17:57:06.484Z,1671040626.484 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-12-14T17:57:06.484Z,1671040626.484 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-12-14T17:57:06.485Z,1671040626.485 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-12-14T17:57:06.645Z,1671040626.645 [BuoyancyServo] Loaded
2022-12-14T17:57:06.645Z,1671040626.645 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-12-14T17:57:06.665Z,1671040626.665 [ElevatorServo] Loaded
2022-12-14T17:57:06.665Z,1671040626.665 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-12-14T17:57:06.684Z,1671040626.684 [MassServo] Loaded
2022-12-14T17:57:06.685Z,1671040626.685 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-12-14T17:57:06.703Z,1671040626.703 [RudderServo] Loaded
2022-12-14T17:57:06.703Z,1671040626.703 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-12-14T17:57:06.718Z,1671040626.718 [ThrusterHE] Loaded
2022-12-14T17:57:06.718Z,1671040626.718 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-12-14T17:57:06.719Z,1671040626.719 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-12-14T17:57:06.720Z,1671040626.720 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-12-14T17:57:06.793Z,1671040626.793 [DepthRateCalculator] Loaded
2022-12-14T17:57:06.794Z,1671040626.794 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-12-14T17:57:06.798Z,1671040626.798 [PitchRateCalculator] Loaded
2022-12-14T17:57:06.799Z,1671040626.799 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-12-14T17:57:06.809Z,1671040626.809 [SpeedCalculator] Loaded
2022-12-14T17:57:06.809Z,1671040626.809 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-12-14T17:57:06.813Z,1671040626.813 [YawRateCalculator] Loaded
2022-12-14T17:57:06.814Z,1671040626.814 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-12-14T17:57:06.832Z,1671040626.832 [ElevatorOffsetCalculator] Loaded
2022-12-14T17:57:06.832Z,1671040626.832 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-12-14T17:57:06.833Z,1671040626.833 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-12-14T17:57:06.833Z,1671040626.833 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-12-14T17:57:06.978Z,1671040626.978 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-12-14T17:57:06.978Z,1671040626.978 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-12-14T17:57:06.992Z,1671040626.992 [NavChart] Loaded
2022-12-14T17:57:06.992Z,1671040626.992 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-12-14T17:57:06.998Z,1671040626.998 [UniversalFixResidualReporter] Loaded
2022-12-14T17:57:06.998Z,1671040626.998 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-12-14T17:57:06.999Z,1671040626.999 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-12-14T17:57:06.999Z,1671040626.999 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-12-14T17:57:07.705Z,1671040627.705 [AHRS_M2] Loaded
2022-12-14T17:57:07.706Z,1671040627.706 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-12-14T17:57:07.956Z,1671040627.956 [BackseatComponent] Loaded
2022-12-14T17:57:07.956Z,1671040627.956 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-12-14T17:57:07.996Z,1671040627.996 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408D14E0
2022-12-14T17:57:07.996Z,1671040627.996 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 8954
2022-12-14T17:57:07.999Z,1671040627.999 [LcmUniversalReporter] Loaded
2022-12-14T17:57:07.999Z,1671040627.999 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-12-14T17:57:08.845Z,1671040628.845 [BPC1] Loaded
2022-12-14T17:57:08.845Z,1671040628.845 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-12-14T17:57:08.941Z,1671040628.941 [DataOverHttps] Loaded
2022-12-14T17:57:08.941Z,1671040628.941 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-12-14T17:57:08.942Z,1671040628.942 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409014E0
2022-12-14T17:57:08.943Z,1671040628.943 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8955
2022-12-14T17:57:08.964Z,1671040628.964 [Depth_Keller] Loaded
2022-12-14T17:57:08.964Z,1671040628.964 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-12-14T17:57:08.969Z,1671040628.969 [DropWeight] Loaded
2022-12-14T17:57:08.969Z,1671040628.969 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-12-14T17:57:09.032Z,1671040629.032 [NAL9602] Loaded
2022-12-14T17:57:09.033Z,1671040629.033 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-12-14T17:57:09.063Z,1671040629.063 [Onboard] Loaded
2022-12-14T17:57:09.064Z,1671040629.064 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-12-14T17:57:09.065Z,1671040629.065 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409314E0
2022-12-14T17:57:09.065Z,1671040629.065 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8956
2022-12-14T17:57:09.077Z,1671040629.077 [Power24vConverter] Loaded
2022-12-14T17:57:09.078Z,1671040629.078 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-12-14T17:57:09.091Z,1671040629.091 [Radio_Surface] Loaded
2022-12-14T17:57:09.092Z,1671040629.092 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-12-14T17:57:09.093Z,1671040629.093 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2022-12-14T17:57:09.093Z,1671040629.093 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8957
2022-12-14T17:57:09.186Z,1671040629.186 [DAT] Loaded
2022-12-14T17:57:09.186Z,1671040629.186 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-12-14T17:57:09.187Z,1671040629.187 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2022-12-14T17:57:09.188Z,1671040629.188 [DAT ThreadHandler](INFO): Protected caller Thread ID is 8958
2022-12-14T17:57:09.188Z,1671040629.188 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-12-14T17:57:09.189Z,1671040629.189 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-12-14T17:57:09.473Z,1671040629.473 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-12-14T17:57:09.474Z,1671040629.474 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-12-14T17:57:09.939Z,1671040629.939 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-12-14T17:57:09.940Z,1671040629.940 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-12-14T17:57:09.985Z,1671040629.985 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-12-14T17:57:09.986Z,1671040629.986 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-12-14T17:57:10.212Z,1671040630.212 [CTD_Seabird] Loaded
2022-12-14T17:57:10.212Z,1671040630.212 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-12-14T17:57:10.238Z,1671040630.238 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ABC4E0
2022-12-14T17:57:10.238Z,1671040630.238 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8959
2022-12-14T17:57:10.261Z,1671040630.261 [PAR_Licor] Loaded
2022-12-14T17:57:10.262Z,1671040630.262 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-12-14T17:57:10.293Z,1671040630.293 [WetLabsBB2FL] Loaded
2022-12-14T17:57:10.293Z,1671040630.293 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-12-14T17:57:10.294Z,1671040630.294 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2022-12-14T17:57:10.295Z,1671040630.295 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8960
2022-12-14T17:57:10.296Z,1671040630.296 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-12-14T17:57:10.296Z,1671040630.296 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-12-14T17:57:10.666Z,1671040630.666 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-12-14T17:57:10.668Z,1671040630.668 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-12-14T17:57:10.840Z,1671040630.840 [SBIT](DEBUG): Construct Startup Built In Test.
2022-12-14T17:57:10.849Z,1671040630.849 [SBIT] Loaded
2022-12-14T17:57:10.849Z,1671040630.849 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-12-14T17:57:10.852Z,1671040630.852 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-12-14T17:57:10.866Z,1671040630.866 [IBIT] Loaded
2022-12-14T17:57:10.866Z,1671040630.866 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-12-14T17:57:10.873Z,1671040630.873 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-12-14T17:57:10.978Z,1671040630.978 [CBIT] Loaded
2022-12-14T17:57:10.978Z,1671040630.978 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-12-14T17:57:10.978Z,1671040630.978 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-12-14T17:57:10.985Z,1671040630.985 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-12-14T17:57:10.988Z,1671040630.988 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-12-14T17:57:10.999Z,1671040630.999 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-12-14T17:57:11.002Z,1671040631.002 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BCF4E0
2022-12-14T17:57:11.002Z,1671040631.002 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8961
2022-12-14T17:57:11.007Z,1671040631.007 [Supervisor](INFO): Main Thread ID is 8866
2022-12-14T17:57:11.007Z,1671040631.007 [Supervisor](DEBUG): Running supervisor.
2022-12-14T17:57:11.007Z,1671040631.007 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8962
2022-12-14T17:57:11.008Z,1671040631.008 [CommandExec](INFO): Initializing the command executive.
2022-12-14T17:57:11.009Z,1671040631.009 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8963
2022-12-14T17:57:11.016Z,1671040631.016 [controlThread ThreadHandler](INFO): Handler Thread ID is 8964
2022-12-14T17:57:11.017Z,1671040631.017 [controlThread](DEBUG): Initializing ControlThread
2022-12-14T17:57:11.018Z,1671040631.018 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-12-14T17:57:11.019Z,1671040631.019 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-12-14T17:57:11.020Z,1671040631.020 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-12-14T17:57:11.021Z,1671040631.021 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-12-14T17:57:11.022Z,1671040631.022 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-12-14T17:57:11.022Z,1671040631.022 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-12-14T17:57:11.023Z,1671040631.023 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-12-14T17:57:11.023Z,1671040631.023 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-12-14T17:57:11.023Z,1671040631.023 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-12-14T17:57:11.024Z,1671040631.024 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-12-14T17:57:11.025Z,1671040631.025 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-12-14T17:57:11.031Z,1671040631.031 [SBIT](INFO): Initialize SBIT Component.
2022-12-14T17:57:11.032Z,1671040631.032 [SBIT](IMPORTANT): git: 2022-11-28
2022-12-14T17:57:11.032Z,1671040631.032 [SBIT](INFO): git hash: ae900ceef0992f02fc7e77b26b775dfa5c801999
2022-12-14T17:57:11.032Z,1671040631.032 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-12-14T17:57:11.033Z,1671040631.033 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-12-14T17:57:11.035Z,1671040631.035 [SBIT](INFO): Beginning SBIT in 61.000000 seconds.
2022-12-14T17:57:11.035Z,1671040631.035 [IBIT](INFO): Initialize IBIT Component.
2022-12-14T17:57:11.036Z,1671040631.036 [CBIT](DEBUG): Initialize CBIT Component.
2022-12-14T17:57:11.037Z,1671040631.037 [logger ThreadHandler](INFO): Handler Thread ID is 8965
2022-12-14T17:57:11.047Z,1671040631.047 [CBIT](DEBUG): Initialized mux pins.
2022-12-14T17:57:11.047Z,1671040631.047 [CBIT](DEBUG): Initializing the watchdog timer.
2022-12-14T17:57:11.056Z,1671040631.056 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 8966
2022-12-14T17:57:11.068Z,1671040631.068 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8967
2022-12-14T17:57:11.068Z,1671040631.068 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-12-14T17:57:11.071Z,1671040631.071 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-12-14T17:57:11.072Z,1671040631.072 [CBIT](DEBUG): Initializing heartbeat.
2022-12-14T17:57:11.080Z,1671040631.080 [Onboard ThreadHandler](INFO): Handler Thread ID is 8968
2022-12-14T17:57:11.109Z,1671040631.109 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8969
2022-12-14T17:57:11.124Z,1671040631.124 [DAT ThreadHandler](INFO): Handler Thread ID is 8970
2022-12-14T17:57:11.124Z,1671040631.124 [DAT](INFO): Powering up
2022-12-14T17:57:11.124Z,1671040631.124 [DAT](DEBUG): Initializing DAT.
2022-12-14T17:57:11.128Z,1671040631.128 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8972
2022-12-14T17:57:11.129Z,1671040631.129 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-12-14T17:57:11.132Z,1671040631.132 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8974
2022-12-14T17:57:11.136Z,1671040631.136 [WetLabsBB2FL](INFO): Powering up
2022-12-14T17:57:11.137Z,1671040631.137 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8976
2022-12-14T17:57:11.143Z,1671040631.143 [CBIT](DEBUG): Deactivating GF circuits.
2022-12-14T17:57:11.143Z,1671040631.143 [CBIT](DEBUG): Deactivating emergency mode.
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-12-14T17:57:11.145Z,1671040631.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-12-14T17:57:11.146Z,1671040631.146 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-12-14T17:57:11.146Z,1671040631.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-12-14T17:57:11.179Z,1671040631.179 [CBIT](DEBUG): Backplane powered.
2022-12-14T17:57:11.180Z,1671040631.180 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-12-14T17:57:11.220Z,1671040631.220 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-14T17:57:11.247Z,1671040631.247 [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>


2022-12-14T17:57:11.248Z,1671040631.248 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-12-14T17:57:11.331Z,1671040631.331 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-12-14T17:57:11.333Z,1671040631.333 [Default:A.Wait](DEBUG): Construct Wait.
2022-12-14T17:57:11.352Z,1671040631.352 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-14T17:57:11.406Z,1671040631.406 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-12-14T17:57:11.425Z,1671040631.425 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-12-14T17:57:11.431Z,1671040631.431 [Default:E.Execute](DEBUG): Construct Execute.
2022-12-14T17:57:11.447Z,1671040631.447 [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>


2022-12-14T17:57:11.468Z,1671040631.468 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,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,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T17:57:11.474Z,1671040631.474 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-12-14T17:57:11.515Z,1671040631.515 [Radio_Surface](INFO): Powering up
2022-12-14T17:57:11.566Z,1671040631.566 [Power24vConverter](INFO): Powering up.
2022-12-14T17:57:11.616Z,1671040631.616 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:11.623Z,1671040631.623 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-12-14T17:57:11.624Z,1671040631.624 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:11.632Z,1671040631.632 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-12-14T17:57:11.633Z,1671040631.633 [MassServo](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:11.639Z,1671040631.639 [MassServo](DEBUG): Initializing MassServo.
2022-12-14T17:57:11.640Z,1671040631.640 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:11.647Z,1671040631.647 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-14T17:57:11.648Z,1671040631.648 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:11.655Z,1671040631.655 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-12-14T17:57:12.631Z,1671040632.631 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-12-14T17:57:12.631Z,1671040632.631 [RudderServo](FAULT): Rudder failed to initialize
2022-12-14T17:57:12.631Z,1671040632.631 [RudderServo] Communications Fault, FailCount= 1
2022-12-14T17:57:12.631Z,1671040632.631 [RudderServo](ERROR): Communications Fault
2022-12-14T17:57:12.636Z,1671040632.636 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-12-14T17:57:12.828Z,1671040632.828 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-14T17:57:12.828Z,1671040632.828 [RudderServo](INFO): Powering down
2022-12-14T17:57:13.243Z,1671040633.243 [WetLabsBB2FL](INFO): Powering down
2022-12-14T17:57:13.524Z,1671040633.524 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-14T17:57:13.647Z,1671040633.647 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-14T17:57:13.652Z,1671040633.652 [CBIT](INFO): Clearing failed state for component RudderServo
2022-12-14T17:57:13.652Z,1671040633.652 [RudderServo] No Fault, FailCount= 1
2022-12-14T17:57:17.384Z,1671040637.384 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-12-14T17:57:23.224Z,1671040643.224 [DAT](INFO): DAT read: 

2022-12-14T17:57:23.225Z,1671040643.225 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-12-14T17:57:24.988Z,1671040644.988 [DAT](INFO): DAT read: MF Frequency Band

2022-12-14T17:57:24.989Z,1671040644.989 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-12-14T17:57:24.990Z,1671040644.990 [DAT](INFO): DAT read: Dec 14 2022 17:57:18 

2022-12-14T17:57:25.021Z,1671040645.021 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004910
2022-12-14T17:57:25.996Z,1671040645.996 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-12-14T17:57:25.997Z,1671040645.997 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-12-14T17:57:25.998Z,1671040645.998 [DAT](INFO): commRate: 800
2022-12-14T17:57:28.063Z,1671040648.063 [DAT](INFO): entering command mode
2022-12-14T17:57:28.264Z,1671040648.264 [DAT](INFO): DAT read: 

2022-12-14T17:57:28.264Z,1671040648.264 [DAT](INFO): DAT read: user:1>

2022-12-14T17:57:28.265Z,1671040648.265 [DAT](INFO): setting verbose to 3
2022-12-14T17:57:28.516Z,1671040648.516 [DAT](INFO): DAT read: user:1>

2022-12-14T17:57:28.517Z,1671040648.517 [DAT](INFO): DAT read: Verbose         | 3           

2022-12-14T17:57:28.517Z,1671040648.517 [DAT](INFO): set verbose to 3
2022-12-14T17:57:28.518Z,1671040648.518 [DAT](INFO): setting DatVerbose to 27440
2022-12-14T17:57:28.768Z,1671040648.768 [DAT](INFO): DAT read: user:2>

2022-12-14T17:57:28.769Z,1671040648.769 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-12-14T17:57:28.769Z,1671040648.769 [DAT](INFO): set DatVerbose to 27440
2022-12-14T17:57:28.769Z,1671040648.769 [DAT](INFO): setting transmit power to 8
2022-12-14T17:57:29.020Z,1671040649.020 [DAT](INFO): DAT read: user:3>

2022-12-14T17:57:29.021Z,1671040649.021 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-12-14T17:57:29.021Z,1671040649.021 [DAT](INFO): set transmit power to 8
2022-12-14T17:57:29.021Z,1671040649.021 [DAT](INFO): setting local address to 5
2022-12-14T17:57:29.272Z,1671040649.272 [DAT](INFO): DAT read: user:4>

2022-12-14T17:57:29.273Z,1671040649.273 [DAT](INFO): DAT read: LocalAddr       | 5           

2022-12-14T17:57:29.273Z,1671040649.273 [DAT](INFO): set local address to 5
2022-12-14T17:57:29.274Z,1671040649.274 [DAT](INFO): Setting time to: 17:57:29 And date to:12/14/2022
2022-12-14T17:57:29.524Z,1671040649.524 [DAT](INFO): DAT read: user:5>

2022-12-14T17:57:29.527Z,1671040649.527 [DAT](INFO): DAT read: Wed Dec 14, 2022  17:57:29  

2022-12-14T17:57:29.529Z,1671040649.529 [DAT](INFO): Local DAT time set to Wed Dec 14, 2022  17:57:29  

2022-12-14T17:57:39.365Z,1671040659.365 [NAL9602](INFO): Powering up NAL9602
2022-12-14T17:57:50.277Z,1671040670.277 [NAL9602](INFO): NAL9602 initialized
2022-12-14T17:58:12.530Z,1671040692.530 [SBIT](IMPORTANT): Beginning Startup BIT
2022-12-14T17:58:12.534Z,1671040692.534 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-14T17:58:23.422Z,1671040703.422 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.015959
CHAN A1 (24V): -0.008164
CHAN A2 (12V): -0.004634
CHAN A3 (5V): -0.002458
CHAN B0 (3.3V): -0.000645
CHAN B1 (3.15aV): -0.001347
CHAN B2 (3.15bV): -0.001090
CHAN B3 (GND): -0.000338
OPEN: 0.004832
Full Scale: +/- 1 mA
2022-12-14T17:59:06.665Z,1671040746.665 [SBIT](IMPORTANT): SBIT PASSED
2022-12-14T17:59:06.665Z,1671040746.665 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): CTD_Seabird.minSalinityBound=0 practical_salinity_unit;

2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-14T17:59:06.666Z,1671040746.666 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-14T17:59:06.667Z,1671040746.667 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2022-12-14T17:59:06.667Z,1671040746.667 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=30 ampere_hour;

2022-12-14T17:59:06.667Z,1671040746.667 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2022-12-14T17:59:06.667Z,1671040746.667 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=324.282117 cubic_centimeter;

2022-12-14T17:59:06.667Z,1671040746.667 [SBIT](IMPORTANT): VerticalControl.massDefault=10.355450 millimeter;

2022-12-14T17:59:07.072Z,1671040747.072 [MissionManager](IMPORTANT): Started mission Startup
2022-12-14T17:59:07.072Z,1671040747.072 [Startup] Running Loop=1
2022-12-14T17:59:07.073Z,1671040747.073 [Startup](DEBUG): Aggregate::initialize Startup
2022-12-14T17:59:07.073Z,1671040747.073 [Startup:A.GoToSurface] Running Loop=1
2022-12-14T17:59:07.073Z,1671040747.073 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-14T17:59:07.073Z,1671040747.073 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-14T17:59:07.074Z,1671040747.074 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-14T17:59:07.074Z,1671040747.074 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-14T17:59:07.074Z,1671040747.074 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-14T17:59:07.075Z,1671040747.075 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-14T17:59:07.076Z,1671040747.076 [Startup:StartupSatComms] Running Loop=1
2022-12-14T17:59:07.076Z,1671040747.076 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-12-14T17:59:07.077Z,1671040747.077 [Startup:StartupSatComms:A] Running Loop=1
2022-12-14T17:59:07.455Z,1671040747.455 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-12-14T17:59:39.419Z,1671040779.419 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T17:59:53.082Z,1671040793.082 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:00:06.883Z,1671040806.883 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:00:07.259Z,1671040807.259 [Startup:StartupSatComms:A](INFO): Timed out from 2022-12-14T17:59:07.1Z
2022-12-14T18:00:07.259Z,1671040807.259 [Startup:StartupSatComms:A] Stopped
2022-12-14T18:00:07.259Z,1671040807.259 [Startup:StartupSatComms:B] Running Loop=1
2022-12-14T18:00:07.661Z,1671040807.661 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-14T18:00:11.278Z,1671040811.278 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-12-14T18:00:11.278Z,1671040811.278 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:00:11.328Z,1671040811.328 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:00:11.682Z,1671040811.682 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:00:11.682Z,1671040811.682 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-12-14T18:00:14.164Z,1671040814.164 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221205T223321/Courier0010.lzma
2022-12-14T18:00:15.165Z,1671040815.165 [DataOverHttps](INFO): Moved sent file to Logs/20221205T223321/Courier0010.lzma.bak
2022-12-14T18:00:15.165Z,1671040815.165 [DataOverHttps](INFO): SBD MOMSN=17395320
2022-12-14T18:00:20.658Z,1671040820.658 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:00:30.823Z,1671040830.823 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221214T175659/Courier0000.lzma
2022-12-14T18:00:31.825Z,1671040831.825 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0000.lzma.bak
2022-12-14T18:00:31.825Z,1671040831.825 [DataOverHttps](INFO): SBD MOMSN=17395330
2022-12-14T18:00:33.993Z,1671040833.993 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:00:40.115Z,1671040840.115 [CommandExec](IMPORTANT): got command get Onboard.Pressure
2022-12-14T18:00:40.120Z,1671040840.120 [CommandExec](IMPORTANT): Onboard.Pressure 62977.414062 Pa
2022-12-14T18:00:47.214Z,1671040847.214 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:00:49.963Z,1671040849.963 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2022-12-14T18:00:49.967Z,1671040849.967 [CommandExec](IMPORTANT): Onboard.Humidity 11.360029 %
2022-12-14T18:00:51.248Z,1671040851.248 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20221205T223321/Express0011.lzma
2022-12-14T18:00:52.245Z,1671040852.245 [DataOverHttps](INFO): Moved sent file to Logs/20221205T223321/Express0011.lzma.bak
2022-12-14T18:00:52.245Z,1671040852.245 [DataOverHttps](INFO): SBD MOMSN=17395333
2022-12-14T18:01:00.547Z,1671040860.547 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:01:05.920Z,1671040865.920 [CommandExec](IMPORTANT): got command failComponent
2022-12-14T18:01:05.920Z,1671040865.920 [CommandExec](IMPORTANT): Failed components:
2022-12-14T18:01:05.920Z,1671040865.920 [CommandExec](IMPORTANT): No failed Components.
2022-12-14T18:01:07.454Z,1671040867.454 [Startup:StartupSatComms:B](INFO): Timed out from 2022-12-14T18:00:07.3Z
2022-12-14T18:01:07.454Z,1671040867.454 [Startup:StartupSatComms:B] Stopped
2022-12-14T18:01:07.454Z,1671040867.454 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-12-14T18:01:07.454Z,1671040867.454 [Startup:StartupSatComms] Stopped
2022-12-14T18:01:07.454Z,1671040867.454 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-12-14T18:01:07.455Z,1671040867.455 [Startup](INFO): Completed Startup
2022-12-14T18:01:07.456Z,1671040867.456 [MissionManager](INFO): Startup is completed.
2022-12-14T18:01:07.456Z,1671040867.456 [MissionManager](INFO): Uninitializing Mission Startup
2022-12-14T18:01:07.456Z,1671040867.456 [Startup] Stopped
2022-12-14T18:01:07.456Z,1671040867.456 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-12-14T18:01:07.456Z,1671040867.456 [Startup:A.GoToSurface] Stopped
2022-12-14T18:01:07.456Z,1671040867.456 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-14T18:01:07.849Z,1671040867.849 [MissionManager](IMPORTANT): Started mission Default
2022-12-14T18:01:07.849Z,1671040867.849 [Default] Running Loop=1
2022-12-14T18:01:07.850Z,1671040867.850 [Default](DEBUG): Aggregate::initialize Default
2022-12-14T18:01:07.850Z,1671040867.850 [Default:B.GoToSurface] Running Loop=1
2022-12-14T18:01:07.850Z,1671040867.850 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-14T18:01:07.850Z,1671040867.850 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-14T18:01:07.850Z,1671040867.850 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-14T18:01:07.851Z,1671040867.851 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-14T18:01:07.852Z,1671040867.852 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-14T18:01:07.852Z,1671040867.852 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-14T18:01:07.852Z,1671040867.852 [Default:A.Wait] Running Loop=1
2022-12-14T18:01:07.852Z,1671040867.852 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:01:08.288Z,1671040868.288 [DataOverHttps](INFO): Sending 1017 bytes from file Logs/20221214T175659/Express0001.lzma
2022-12-14T18:01:09.289Z,1671040869.289 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0001.lzma.bak
2022-12-14T18:01:09.289Z,1671040869.289 [DataOverHttps](INFO): SBD MOMSN=17395337
2022-12-14T18:01:14.282Z,1671040874.282 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:01:21.165Z,1671040881.165 [Default:A.Wait](INFO): Done Waiting.
2022-12-14T18:01:21.165Z,1671040881.165 [Default:A.Wait] Stopped
2022-12-14T18:01:21.165Z,1671040881.165 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:01:21.570Z,1671040881.570 [Default:CheckIn] Running Loop=1
2022-12-14T18:01:21.570Z,1671040881.570 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:01:21.570Z,1671040881.570 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:01:21.981Z,1671040881.981 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-12-14T18:01:27.614Z,1671040887.614 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:01:40.945Z,1671040900.945 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:01:54.283Z,1671040914.283 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T18:02:53.673Z,1671040973.673 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T18:03:12.263Z,1671040992.263 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-12-14T18:03:12.263Z,1671040992.263 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:03:12.291Z,1671040992.291 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:03:12.678Z,1671040992.678 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:03:12.678Z,1671040992.678 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-12-14T18:04:36.691Z,1671041076.691 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2022-12-14T18:04:36.695Z,1671041076.695 [BPC1](INFO): Received data from all battery sticks.
2022-12-14T18:06:13.267Z,1671041173.267 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-12-14T18:06:13.267Z,1671041173.267 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:06:13.278Z,1671041173.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:06:13.668Z,1671041173.668 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:06:13.669Z,1671041173.669 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-12-14T18:06:21.766Z,1671041181.766 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-14T18:01:21.6Z
2022-12-14T18:06:21.767Z,1671041181.767 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:06:21.767Z,1671041181.767 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:06:22.145Z,1671041182.145 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-14T18:06:28.731Z,1671041188.731 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20221214T175659/Courier0004.lzma
2022-12-14T18:06:29.733Z,1671041189.733 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0004.lzma.bak
2022-12-14T18:06:29.733Z,1671041189.733 [DataOverHttps](INFO): SBD MOMSN=17395362
2022-12-14T18:06:47.955Z,1671041207.955 [DataOverHttps](INFO): Sending 335 bytes from file Logs/20221214T175659/Express0005.lzma
2022-12-14T18:06:48.957Z,1671041208.957 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0005.lzma.bak
2022-12-14T18:06:48.957Z,1671041208.957 [DataOverHttps](INFO): SBD MOMSN=17395364
2022-12-14T18:06:51.661Z,1671041211.661 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:06:51.661Z,1671041211.661 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:06:51.661Z,1671041211.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:07:52.234Z,1671041272.234 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-14T18:07:52.234Z,1671041272.234 [NAL9602] Data Fault, FailCount= 1
2022-12-14T18:07:52.234Z,1671041272.234 [NAL9602](ERROR): Data Fault
2022-12-14T18:07:52.253Z,1671041272.253 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-14T18:07:52.629Z,1671041272.629 [NAL9602](INFO): Powering down
2022-12-14T18:07:53.037Z,1671041273.037 [NAL9602](FAULT): LCB fault: LCB Watchdog Reset. Hardware Overcurrent Shutdown. Current Limiter Activated.
2022-12-14T18:07:53.037Z,1671041273.037 [NAL9602] Hardware Fault, FailCount= 1
2022-12-14T18:07:53.037Z,1671041273.037 [NAL9602](ERROR): Hardware Fault
2022-12-14T18:07:53.456Z,1671041273.456 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-14T18:07:53.457Z,1671041273.457 [NAL9602] No Fault, FailCount= 1
2022-12-14T18:08:22.933Z,1671041302.933 [NAL9602](INFO): Powering up NAL9602
2022-12-14T18:08:33.842Z,1671041313.842 [NAL9602](INFO): NAL9602 initialized
2022-12-14T18:09:14.247Z,1671041354.247 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-12-14T18:09:14.247Z,1671041354.247 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:09:14.263Z,1671041354.263 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:09:14.666Z,1671041354.666 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:09:14.666Z,1671041354.666 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-12-14T18:11:52.302Z,1671041512.302 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:11:52.302Z,1671041512.302 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:11:52.302Z,1671041512.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:11:52.302Z,1671041512.302 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:11:52.717Z,1671041512.717 [Default:CheckIn:D] Stopped
2022-12-14T18:11:52.717Z,1671041512.717 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.747784 min 
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn:E] Stopped
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn] Stopped
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn](INFO): Running loop #2
2022-12-14T18:11:53.109Z,1671041513.109 [Default:CheckIn] Running Loop=2
2022-12-14T18:11:53.110Z,1671041513.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:11:53.110Z,1671041513.110 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:12:15.356Z,1671041535.356 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-12-14T18:12:15.356Z,1671041535.356 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:12:15.366Z,1671041535.366 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:12:15.740Z,1671041535.740 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:12:15.741Z,1671041535.741 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-12-14T18:15:16.370Z,1671041716.370 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-12-14T18:15:16.370Z,1671041716.370 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-14T18:15:16.381Z,1671041716.381 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-14T18:15:16.792Z,1671041716.792 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-14T18:15:16.793Z,1671041716.793 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-12-14T18:16:53.325Z,1671041813.325 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-14T18:11:53.1Z
2022-12-14T18:16:53.325Z,1671041813.325 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:16:53.325Z,1671041813.325 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:17:00.911Z,1671041820.911 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221214T175659/Courier0007.lzma
2022-12-14T18:17:01.913Z,1671041821.913 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0007.lzma.bak
2022-12-14T18:17:01.913Z,1671041821.913 [DataOverHttps](INFO): SBD MOMSN=17395387
2022-12-14T18:17:23.591Z,1671041843.591 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20221214T175659/Express0008.lzma
2022-12-14T18:17:24.593Z,1671041844.593 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0008.lzma.bak
2022-12-14T18:17:24.593Z,1671041844.593 [DataOverHttps](INFO): SBD MOMSN=17395389
2022-12-14T18:17:27.388Z,1671041847.388 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:17:27.388Z,1671041847.388 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:17:27.388Z,1671041847.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:17:51.979Z,1671041871.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181750.00,A,3648.16969,N,12147.27938,W,0.175,290.41,141222,,,D*76
2022-12-14T18:17:52.011Z,1671041872.011 [NAL9602](INFO): GPS fix at 20221214T181750: (36.802828, -121.787990)
2022-12-14T18:18:24.308Z,1671041904.308 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T18:22:28.023Z,1671042148.023 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:22:28.023Z,1671042148.023 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:22:28.024Z,1671042148.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:22:28.024Z,1671042148.024 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:22:28.397Z,1671042148.397 [Default:CheckIn:D] Stopped
2022-12-14T18:22:28.397Z,1671042148.397 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:22:28.831Z,1671042148.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.342452 min 
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn:E] Stopped
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn] Stopped
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn](INFO): Running loop #3
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn] Running Loop=3
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:22:28.832Z,1671042148.832 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:22:30.806Z,1671042150.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182230.00,A,3648.16364,N,12147.28119,W,0.914,290.41,141222,,,D*7A
2022-12-14T18:22:30.809Z,1671042150.809 [NAL9602](INFO): GPS fix at 20221214T182230: (36.802727, -121.788020)
2022-12-14T18:22:30.819Z,1671042150.819 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:22:30.820Z,1671042150.820 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:22:37.963Z,1671042157.963 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20221214T175659/Courier0010.lzma
2022-12-14T18:22:38.965Z,1671042158.965 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0010.lzma.bak
2022-12-14T18:22:38.965Z,1671042158.965 [DataOverHttps](INFO): SBD MOMSN=17395394
2022-12-14T18:22:56.223Z,1671042176.223 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20221214T175659/Express0011.lzma
2022-12-14T18:22:57.225Z,1671042177.225 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0011.lzma.bak
2022-12-14T18:22:57.225Z,1671042177.225 [DataOverHttps](INFO): SBD MOMSN=17395397
2022-12-14T18:22:59.927Z,1671042179.927 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:22:59.927Z,1671042179.927 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:22:59.927Z,1671042179.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:27:33.509Z,1671042453.509 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T18:28:00.599Z,1671042480.599 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:28:00.599Z,1671042480.599 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:28:00.603Z,1671042480.603 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:28:00.603Z,1671042480.603 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:28:01.008Z,1671042481.008 [Default:CheckIn:D] Stopped
2022-12-14T18:28:01.008Z,1671042481.008 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:28:01.430Z,1671042481.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.885974 min 
2022-12-14T18:28:01.431Z,1671042481.431 [Default:CheckIn:E] Stopped
2022-12-14T18:28:01.435Z,1671042481.435 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:28:01.435Z,1671042481.435 [Default:CheckIn] Stopped
2022-12-14T18:28:01.435Z,1671042481.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:28:01.435Z,1671042481.435 [Default:CheckIn](INFO): Running loop #4
2022-12-14T18:28:01.435Z,1671042481.435 [Default:CheckIn] Running Loop=4
2022-12-14T18:28:01.436Z,1671042481.436 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:28:01.436Z,1671042481.436 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:28:03.402Z,1671042483.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182802.00,A,3648.16718,N,12147.28091,W,0.039,290.41,141222,,,D*79
2022-12-14T18:28:03.405Z,1671042483.405 [NAL9602](INFO): GPS fix at 20221214T182802: (36.802786, -121.788015)
2022-12-14T18:28:03.415Z,1671042483.415 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:28:03.415Z,1671042483.415 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:28:11.930Z,1671042491.930 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0013.lzma
2022-12-14T18:28:12.933Z,1671042492.933 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0013.lzma.bak
2022-12-14T18:28:12.933Z,1671042492.933 [DataOverHttps](INFO): SBD MOMSN=17395400
2022-12-14T18:28:35.381Z,1671042515.381 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T18:28:36.171Z,1671042516.171 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221214T175659/Express0014.lzma
2022-12-14T18:28:37.169Z,1671042517.169 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0014.lzma.bak
2022-12-14T18:28:37.169Z,1671042517.169 [DataOverHttps](INFO): SBD MOMSN=17395403
2022-12-14T18:28:39.891Z,1671042519.891 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:28:39.891Z,1671042519.891 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:28:39.891Z,1671042519.891 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:33:40.443Z,1671042820.443 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:33:40.443Z,1671042820.443 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:33:40.443Z,1671042820.443 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:33:40.443Z,1671042820.443 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:33:40.857Z,1671042820.857 [Default:CheckIn:D] Stopped
2022-12-14T18:33:40.857Z,1671042820.857 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.550122 min 
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn:E] Stopped
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn] Stopped
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:33:41.255Z,1671042821.255 [Default:CheckIn](INFO): Running loop #5
2022-12-14T18:33:41.256Z,1671042821.256 [Default:CheckIn] Running Loop=5
2022-12-14T18:33:41.256Z,1671042821.256 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:33:41.256Z,1671042821.256 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:33:43.266Z,1671042823.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183342.00,A,3648.16670,N,12147.28150,W,0.175,0.00,141222,,,D*73
2022-12-14T18:33:43.269Z,1671042823.269 [NAL9602](INFO): GPS fix at 20221214T183342: (36.802778, -121.788025)
2022-12-14T18:33:43.280Z,1671042823.280 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:33:43.280Z,1671042823.280 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:33:50.599Z,1671042830.599 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0016.lzma
2022-12-14T18:33:51.601Z,1671042831.601 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0016.lzma.bak
2022-12-14T18:33:51.601Z,1671042831.601 [DataOverHttps](INFO): SBD MOMSN=17395407
2022-12-14T18:34:10.091Z,1671042850.091 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221214T175659/Express0017.lzma
2022-12-14T18:34:11.093Z,1671042851.093 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0017.lzma.bak
2022-12-14T18:34:11.093Z,1671042851.093 [DataOverHttps](INFO): SBD MOMSN=17395410
2022-12-14T18:34:13.589Z,1671042853.589 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:34:13.590Z,1671042853.590 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:34:13.590Z,1671042853.590 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:38:45.576Z,1671043125.576 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T18:39:14.301Z,1671043154.301 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:39:14.302Z,1671043154.302 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:39:14.302Z,1671043154.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:39:14.302Z,1671043154.302 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:39:14.718Z,1671043154.718 [Default:CheckIn:D] Stopped
2022-12-14T18:39:14.718Z,1671043154.718 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.114473 min 
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn:E] Stopped
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn] Stopped
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:39:15.092Z,1671043155.092 [Default:CheckIn](INFO): Running loop #6
2022-12-14T18:39:15.093Z,1671043155.093 [Default:CheckIn] Running Loop=6
2022-12-14T18:39:15.093Z,1671043155.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:39:15.093Z,1671043155.093 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:39:17.087Z,1671043157.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183916.00,A,3648.16650,N,12147.28295,W,0.428,0.00,141222,,,D*7D
2022-12-14T18:39:17.089Z,1671043157.089 [NAL9602](INFO): GPS fix at 20221214T183916: (36.802775, -121.788049)
2022-12-14T18:39:17.120Z,1671043157.120 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:39:17.120Z,1671043157.120 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:39:25.395Z,1671043165.395 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0019.lzma
2022-12-14T18:39:26.397Z,1671043166.397 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0019.lzma.bak
2022-12-14T18:39:26.397Z,1671043166.397 [DataOverHttps](INFO): SBD MOMSN=17395413
2022-12-14T18:39:43.571Z,1671043183.571 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221214T175659/Express0020.lzma
2022-12-14T18:39:44.573Z,1671043184.573 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0020.lzma.bak
2022-12-14T18:39:44.573Z,1671043184.573 [DataOverHttps](INFO): SBD MOMSN=17395416
2022-12-14T18:39:47.007Z,1671043187.007 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:39:47.007Z,1671043187.007 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:39:47.007Z,1671043187.007 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:39:49.417Z,1671043189.417 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T18:43:33.300Z,1671043413.300 [CommandExec](IMPORTANT): got command failComponent
2022-12-14T18:43:33.300Z,1671043413.300 [CommandExec](IMPORTANT): Failed components:
2022-12-14T18:43:33.300Z,1671043413.300 [CommandExec](IMPORTANT): No failed Components.
2022-12-14T18:44:47.643Z,1671043487.643 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:44:47.643Z,1671043487.643 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:44:47.643Z,1671043487.643 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:44:47.643Z,1671043487.643 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:44:48.051Z,1671043488.051 [Default:CheckIn:D] Stopped
2022-12-14T18:44:48.051Z,1671043488.051 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:44:48.422Z,1671043488.422 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.670032 min 
2022-12-14T18:44:48.422Z,1671043488.422 [Default:CheckIn:E] Stopped
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn] Stopped
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn](INFO): Running loop #7
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn] Running Loop=7
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:44:48.423Z,1671043488.423 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:44:50.430Z,1671043490.430 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184449.00,A,3648.16609,N,12147.28280,W,0.778,0.00,141222,,,D*73
2022-12-14T18:44:50.433Z,1671043490.433 [NAL9602](INFO): GPS fix at 20221214T184449: (36.802768, -121.788047)
2022-12-14T18:44:50.444Z,1671043490.444 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:44:50.444Z,1671043490.444 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:44:59.423Z,1671043499.423 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0022.lzma
2022-12-14T18:45:00.425Z,1671043500.425 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0022.lzma.bak
2022-12-14T18:45:00.425Z,1671043500.425 [DataOverHttps](INFO): SBD MOMSN=17395421
2022-12-14T18:45:17.611Z,1671043517.611 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20221214T175659/Express0023.lzma
2022-12-14T18:45:18.613Z,1671043518.613 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0023.lzma.bak
2022-12-14T18:45:18.613Z,1671043518.613 [DataOverHttps](INFO): SBD MOMSN=17395426
2022-12-14T18:45:21.106Z,1671043521.106 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:45:21.106Z,1671043521.106 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:45:21.106Z,1671043521.106 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:48:27.097Z,1671043707.097 [CommandLine](INFO): End of History
2022-12-14T18:48:32.365Z,1671043712.365 [CommandExec](IMPORTANT): got command get Onboard.Pressure
2022-12-14T18:48:32.366Z,1671043712.366 [CommandExec](IMPORTANT): Onboard.Pressure 62808.210938 Pa
2022-12-14T18:48:46.558Z,1671043726.558 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2022-12-14T18:48:46.558Z,1671043726.558 [CommandExec](IMPORTANT): Onboard.Humidity 11.305091 %
2022-12-14T18:49:53.481Z,1671043793.481 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T18:50:21.808Z,1671043821.808 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:50:21.808Z,1671043821.808 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:50:21.808Z,1671043821.808 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:50:21.809Z,1671043821.809 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:50:22.206Z,1671043822.206 [Default:CheckIn:D] Stopped
2022-12-14T18:50:22.206Z,1671043822.206 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.239278 min 
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn:E] Stopped
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn] Stopped
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:50:22.615Z,1671043822.615 [Default:CheckIn](INFO): Running loop #8
2022-12-14T18:50:22.616Z,1671043822.616 [Default:CheckIn] Running Loop=8
2022-12-14T18:50:22.616Z,1671043822.616 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:50:22.616Z,1671043822.616 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:50:24.614Z,1671043824.614 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185023.00,A,3648.16372,N,12147.28229,W,0.603,12.60,141222,,,D*48
2022-12-14T18:50:24.617Z,1671043824.617 [NAL9602](INFO): GPS fix at 20221214T185023: (36.802729, -121.788038)
2022-12-14T18:50:24.660Z,1671043824.659 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:50:24.660Z,1671043824.660 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:50:35.279Z,1671043835.279 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0025.lzma
2022-12-14T18:50:37.719Z,1671043837.719 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0025.lzma.bak
2022-12-14T18:50:37.719Z,1671043837.719 [DataOverHttps](INFO): SBD MOMSN=17395439
2022-12-14T18:50:53.928Z,1671043853.928 [DataOverHttps](INFO): Sending 373 bytes from file Logs/20221214T175659/Express0026.lzma
2022-12-14T18:50:54.929Z,1671043854.929 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0026.lzma.bak
2022-12-14T18:50:54.929Z,1671043854.929 [DataOverHttps](INFO): SBD MOMSN=17395442
2022-12-14T18:50:57.456Z,1671043857.456 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T18:50:57.515Z,1671043857.515 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:50:57.515Z,1671043857.515 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:50:57.515Z,1671043857.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T18:55:58.132Z,1671044158.132 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T18:55:58.132Z,1671044158.132 [Default:CheckIn:C.Wait] Stopped
2022-12-14T18:55:58.132Z,1671044158.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T18:55:58.132Z,1671044158.132 [Default:CheckIn:D] Running Loop=1
2022-12-14T18:55:58.523Z,1671044158.523 [Default:CheckIn:D] Stopped
2022-12-14T18:55:58.523Z,1671044158.523 [Default:CheckIn:E] Running Loop=1
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.844548 min 
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn:E] Stopped
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn] Stopped
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn](INFO): Running loop #9
2022-12-14T18:55:58.922Z,1671044158.922 [Default:CheckIn] Running Loop=9
2022-12-14T18:55:58.923Z,1671044158.923 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T18:55:58.923Z,1671044158.923 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T18:56:00.934Z,1671044160.934 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185600.00,A,3648.16219,N,12147.28345,W,0.253,70.61,141222,,,D*4C
2022-12-14T18:56:00.937Z,1671044160.937 [NAL9602](INFO): GPS fix at 20221214T185600: (36.802703, -121.788057)
2022-12-14T18:56:00.955Z,1671044160.955 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T18:56:00.955Z,1671044160.955 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T18:56:08.375Z,1671044168.375 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0028.lzma
2022-12-14T18:56:09.377Z,1671044169.377 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0028.lzma.bak
2022-12-14T18:56:09.377Z,1671044169.377 [DataOverHttps](INFO): SBD MOMSN=17395450
2022-12-14T18:56:31.676Z,1671044191.676 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T18:56:31.755Z,1671044191.755 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T18:56:32.807Z,1671044192.807 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221214T175659/Express0029.lzma
2022-12-14T18:56:33.809Z,1671044193.809 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0029.lzma.bak
2022-12-14T18:56:33.809Z,1671044193.809 [DataOverHttps](INFO): SBD MOMSN=17395453
2022-12-14T18:56:36.548Z,1671044196.548 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T18:56:36.548Z,1671044196.548 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T18:56:36.549Z,1671044196.549 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:01:03.604Z,1671044463.604 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:01:34.325Z,1671044494.325 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:01:37.150Z,1671044497.150 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:01:37.150Z,1671044497.150 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:01:37.150Z,1671044497.150 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:01:37.151Z,1671044497.151 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:01:37.554Z,1671044497.554 [Default:CheckIn:D] Stopped
2022-12-14T19:01:37.554Z,1671044497.554 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.495068 min 
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn:E] Stopped
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn] Stopped
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn](INFO): Running loop #10
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn] Running Loop=10
2022-12-14T19:01:37.959Z,1671044497.959 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:01:37.960Z,1671044497.960 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:01:39.970Z,1671044499.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190139.00,A,3648.16129,N,12147.28232,W,0.272,70.61,141222,,,D*47
2022-12-14T19:01:39.981Z,1671044499.981 [NAL9602](INFO): GPS fix at 20221214T190139: (36.802688, -121.788039)
2022-12-14T19:01:39.991Z,1671044499.991 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:01:39.991Z,1671044499.991 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:01:47.963Z,1671044507.963 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0031.lzma
2022-12-14T19:01:48.965Z,1671044508.965 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0031.lzma.bak
2022-12-14T19:01:48.965Z,1671044508.965 [DataOverHttps](INFO): SBD MOMSN=17395470
2022-12-14T19:02:06.159Z,1671044526.159 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221214T175659/Express0032.lzma
2022-12-14T19:02:07.161Z,1671044527.161 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0032.lzma.bak
2022-12-14T19:02:07.161Z,1671044527.161 [DataOverHttps](INFO): SBD MOMSN=17395473
2022-12-14T19:02:09.885Z,1671044529.885 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:02:09.885Z,1671044529.885 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:02:09.885Z,1671044529.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:02:10.669Z,1671044530.668 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:02:10.751Z,1671044530.751 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:06:42.212Z,1671044802.212 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:07:05.287Z,1671044825.287 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:07:10.592Z,1671044830.592 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:07:10.592Z,1671044830.592 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:07:10.592Z,1671044830.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:07:10.592Z,1671044830.592 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:07:10.979Z,1671044830.979 [Default:CheckIn:D] Stopped
2022-12-14T19:07:10.979Z,1671044830.979 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:07:11.395Z,1671044831.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.052153 min 
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn:E] Stopped
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn] Stopped
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn](INFO): Running loop #11
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn] Running Loop=11
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:07:11.396Z,1671044831.396 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:07:13.382Z,1671044833.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190712.00,A,3648.16267,N,12147.27699,W,0.350,0.00,141222,,,D*7A
2022-12-14T19:07:13.384Z,1671044833.384 [NAL9602](INFO): GPS fix at 20221214T190712: (36.802711, -121.787950)
2022-12-14T19:07:13.413Z,1671044833.413 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:07:13.413Z,1671044833.413 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:07:19.233Z,1671044839.233 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:07:21.783Z,1671044841.783 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0034.lzma
2022-12-14T19:07:22.785Z,1671044842.785 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0034.lzma.bak
2022-12-14T19:07:22.785Z,1671044842.785 [DataOverHttps](INFO): SBD MOMSN=17395478
2022-12-14T19:07:32.565Z,1671044852.565 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:07:39.925Z,1671044859.925 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221214T175659/Express0035.lzma
2022-12-14T19:07:40.925Z,1671044860.925 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0035.lzma.bak
2022-12-14T19:07:40.925Z,1671044860.925 [DataOverHttps](INFO): SBD MOMSN=17395481
2022-12-14T19:07:43.490Z,1671044863.490 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:07:43.490Z,1671044863.490 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:07:43.490Z,1671044863.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:07:45.505Z,1671044865.505 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:07:46.289Z,1671044866.289 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:07:59.619Z,1671044879.619 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:08:12.953Z,1671044892.953 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:08:26.297Z,1671044906.297 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:08:40.029Z,1671044920.029 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:08:53.756Z,1671044933.756 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:09:07.104Z,1671044947.104 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:09:20.890Z,1671044960.890 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T19:10:43.945Z,1671045043.945 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200 cubic_centimeter
2022-12-14T19:10:43.950Z,1671045043.950 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2022-12-14T19:10:44.180Z,1671045044.180 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:11:35.235Z,1671045095.235 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:11:35.236Z,1671045095.236 [CommandExec](IMPORTANT): platform_buoyancy_position 378.027222 cc
2022-12-14T19:11:40.386Z,1671045100.386 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:11:40.387Z,1671045100.387 [CommandExec](IMPORTANT): platform_buoyancy_position 309.265625 cc
2022-12-14T19:12:00.102Z,1671045120.102 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2022-12-14T19:12:00.105Z,1671045120.105 [BPC1](INFO): Received data from all battery sticks.
2022-12-14T19:12:44.130Z,1671045164.130 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:12:44.130Z,1671045164.130 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:12:44.130Z,1671045164.130 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:12:44.130Z,1671045164.130 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:12:44.532Z,1671045164.532 [Default:CheckIn:D] Stopped
2022-12-14T19:12:44.532Z,1671045164.532 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:12:44.946Z,1671045164.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.611369 min 
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn:E] Stopped
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn] Stopped
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn](INFO): Running loop #12
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn] Running Loop=12
2022-12-14T19:12:44.947Z,1671045164.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:12:44.948Z,1671045164.948 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:12:46.950Z,1671045166.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191246.00,A,3648.16234,N,12147.28587,W,0.175,214.29,141222,,,D*73
2022-12-14T19:12:46.953Z,1671045166.953 [NAL9602](INFO): GPS fix at 20221214T191246: (36.802706, -121.788098)
2022-12-14T19:12:46.965Z,1671045166.965 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:12:46.965Z,1671045166.965 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:12:54.487Z,1671045174.487 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20221214T175659/Courier0037.lzma
2022-12-14T19:12:56.493Z,1671045176.493 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0037.lzma.bak
2022-12-14T19:12:56.493Z,1671045176.493 [DataOverHttps](INFO): SBD MOMSN=17395486
2022-12-14T19:13:17.691Z,1671045197.691 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:13:17.775Z,1671045197.775 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:13:18.167Z,1671045198.167 [DataOverHttps](INFO): Sending 389 bytes from file Logs/20221214T175659/Express0038.lzma
2022-12-14T19:13:19.170Z,1671045199.170 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0038.lzma.bak
2022-12-14T19:13:19.170Z,1671045199.170 [DataOverHttps](INFO): SBD MOMSN=17395489
2022-12-14T19:13:21.774Z,1671045201.774 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:13:21.775Z,1671045201.775 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:13:21.775Z,1671045201.775 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:14:10.032Z,1671045250.032 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:14:10.035Z,1671045250.035 [CommandExec](IMPORTANT): platform_mass_position 0.010306 m
2022-12-14T19:14:51.716Z,1671045291.716 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0 millimeter
2022-12-14T19:14:51.720Z,1671045291.720 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2022-12-14T19:14:51.868Z,1671045291.868 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:14:58.938Z,1671045298.938 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:14:58.939Z,1671045298.939 [CommandExec](IMPORTANT): platform_mass_position 0.006501 m
2022-12-14T19:15:23.625Z,1671045323.625 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:15:23.625Z,1671045323.625 [CommandExec](IMPORTANT): platform_mass_position 0.000000 m
2022-12-14T19:15:42.558Z,1671045342.558 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction -10 millimeter
2022-12-14T19:17:49.245Z,1671045469.245 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:17:51.520Z,1671045471.520 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0 millimeter
2022-12-14T19:18:19.980Z,1671045499.980 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:18:22.423Z,1671045502.423 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:18:22.423Z,1671045502.423 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:18:22.423Z,1671045502.423 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:18:22.423Z,1671045502.423 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:18:22.829Z,1671045502.829 [Default:CheckIn:D] Stopped
2022-12-14T19:18:22.830Z,1671045502.830 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:18:23.225Z,1671045503.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.249666 min 
2022-12-14T19:18:23.225Z,1671045503.225 [Default:CheckIn:E] Stopped
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn] Stopped
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn](INFO): Running loop #13
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn] Running Loop=13
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:18:23.226Z,1671045503.226 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:18:25.230Z,1671045505.230 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191824.00,A,3648.16396,N,12147.28124,W,0.136,214.29,141222,,,D*7E
2022-12-14T19:18:25.246Z,1671045505.246 [NAL9602](INFO): GPS fix at 20221214T191824: (36.802733, -121.788021)
2022-12-14T19:18:25.256Z,1671045505.256 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:18:25.256Z,1671045505.256 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:18:35.699Z,1671045515.699 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0040.lzma
2022-12-14T19:18:36.701Z,1671045516.701 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0040.lzma.bak
2022-12-14T19:18:36.701Z,1671045516.701 [DataOverHttps](INFO): SBD MOMSN=17395497
2022-12-14T19:18:51.096Z,1671045531.096 [CommandExec](IMPORTANT): got command get 
2022-12-14T19:18:51.096Z,1671045531.096 [CommandExec](FAULT): Incomplete syntax. Try: help get
2022-12-14T19:18:54.492Z,1671045534.492 [DataOverHttps](INFO): Sending 812 bytes from file Logs/20221214T175659/Express0041.lzma
2022-12-14T19:18:55.493Z,1671045535.493 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0041.lzma.bak
2022-12-14T19:18:55.493Z,1671045535.493 [DataOverHttps](INFO): SBD MOMSN=17395500
2022-12-14T19:18:55.964Z,1671045535.964 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:18:56.047Z,1671045536.047 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:18:59.235Z,1671045539.235 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:18:59.235Z,1671045539.235 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:18:59.243Z,1671045539.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:19:06.163Z,1671045546.163 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:19:06.165Z,1671045546.165 [CommandExec](IMPORTANT): platform_mass_position -0.000000 m
2022-12-14T19:20:14.596Z,1671045614.596 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault 0 millimeter persist
2022-12-14T19:20:32.874Z,1671045632.874 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:20:32.895Z,1671045632.895 [CommandExec](IMPORTANT): platform_mass_position -0.000000 m
2022-12-14T19:20:41.333Z,1671045641.333 [CommandExec](IMPORTANT): got command maintain clear
2022-12-14T19:20:41.683Z,1671045641.683 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,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,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:22:29.710Z,1671045749.710 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:22:29.711Z,1671045749.711 [CommandExec](IMPORTANT): platform_mass_position -0.000000 m
2022-12-14T19:22:45.694Z,1671045765.694 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:22:45.701Z,1671045765.701 [CommandExec](IMPORTANT): platform_buoyancy_position 947.324951 cc
2022-12-14T19:23:27.576Z,1671045807.576 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:23:58.276Z,1671045838.276 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:23:59.920Z,1671045839.920 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:23:59.920Z,1671045839.920 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:23:59.920Z,1671045839.920 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:23:59.920Z,1671045839.920 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:24:00.332Z,1671045840.332 [Default:CheckIn:D] Stopped
2022-12-14T19:24:00.332Z,1671045840.332 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:24:00.747Z,1671045840.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.874699 min 
2022-12-14T19:24:00.747Z,1671045840.747 [Default:CheckIn:E] Stopped
2022-12-14T19:24:00.747Z,1671045840.747 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:24:00.747Z,1671045840.747 [Default:CheckIn] Stopped
2022-12-14T19:24:00.748Z,1671045840.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:24:00.748Z,1671045840.748 [Default:CheckIn](INFO): Running loop #14
2022-12-14T19:24:00.748Z,1671045840.748 [Default:CheckIn] Running Loop=14
2022-12-14T19:24:00.748Z,1671045840.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:24:00.748Z,1671045840.748 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:24:02.722Z,1671045842.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192402.00,A,3648.16305,N,12147.28433,W,0.330,214.29,141222,,,D*78
2022-12-14T19:24:02.725Z,1671045842.725 [NAL9602](INFO): GPS fix at 20221214T192402: (36.802717, -121.788072)
2022-12-14T19:24:02.736Z,1671045842.736 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:24:02.736Z,1671045842.736 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:24:11.663Z,1671045851.663 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0043.lzma
2022-12-14T19:24:12.665Z,1671045852.665 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0043.lzma.bak
2022-12-14T19:24:12.665Z,1671045852.665 [DataOverHttps](INFO): SBD MOMSN=17395521
2022-12-14T19:24:33.549Z,1671045873.549 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:24:33.638Z,1671045873.638 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:24:38.944Z,1671045878.944 [DataOverHttps](INFO): Sending 620 bytes from file Logs/20221214T175659/Express0044.lzma
2022-12-14T19:24:39.945Z,1671045879.945 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0044.lzma.bak
2022-12-14T19:24:39.945Z,1671045879.945 [DataOverHttps](INFO): SBD MOMSN=17395524
2022-12-14T19:24:43.753Z,1671045883.753 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:24:43.753Z,1671045883.753 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:24:43.753Z,1671045883.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:25:46.088Z,1671045946.088 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 15 millimeter
2022-12-14T19:25:46.089Z,1671045946.089 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2022-12-14T19:25:46.336Z,1671045946.336 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:28:42.688Z,1671046122.688 [CommandLine](INFO): End of History
2022-12-14T19:28:43.248Z,1671046123.248 [CommandLine](INFO): End of History
2022-12-14T19:28:54.129Z,1671046134.129 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200 cubic_centimeter
2022-12-14T19:28:54.130Z,1671046134.130 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2022-12-14T19:28:54.357Z,1671046134.357 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:29:05.232Z,1671046145.232 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:29:35.977Z,1671046175.977 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:29:44.482Z,1671046184.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:29:44.482Z,1671046184.482 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:29:44.482Z,1671046184.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:29:44.482Z,1671046184.482 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:29:44.874Z,1671046184.874 [Default:CheckIn:D] Stopped
2022-12-14T19:29:44.875Z,1671046184.875 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.617082 min 
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn:E] Stopped
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn] Stopped
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:29:45.280Z,1671046185.280 [Default:CheckIn](INFO): Running loop #15
2022-12-14T19:29:45.281Z,1671046185.281 [Default:CheckIn] Running Loop=15
2022-12-14T19:29:45.281Z,1671046185.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:29:45.281Z,1671046185.281 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:29:47.290Z,1671046187.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192946.00,A,3648.16160,N,12147.28548,W,0.525,0.00,141222,,,D*77
2022-12-14T19:29:47.292Z,1671046187.292 [NAL9602](INFO): GPS fix at 20221214T192946: (36.802693, -121.788091)
2022-12-14T19:29:47.303Z,1671046187.303 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:29:47.303Z,1671046187.303 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:29:54.895Z,1671046194.895 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0046.lzma
2022-12-14T19:29:55.898Z,1671046195.898 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0046.lzma.bak
2022-12-14T19:29:55.898Z,1671046195.898 [DataOverHttps](INFO): SBD MOMSN=17395541
2022-12-14T19:30:17.998Z,1671046217.998 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:30:18.080Z,1671046218.080 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:30:27.420Z,1671046227.420 [DataOverHttps](INFO): Sending 536 bytes from file Logs/20221214T175659/Express0047.lzma
2022-12-14T19:30:28.421Z,1671046228.421 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0047.lzma.bak
2022-12-14T19:30:28.421Z,1671046228.421 [DataOverHttps](INFO): SBD MOMSN=17395544
2022-12-14T19:30:32.651Z,1671046232.651 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:30:32.651Z,1671046232.651 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:30:32.651Z,1671046232.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:32:26.524Z,1671046346.524 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:32:26.524Z,1671046346.524 [CommandExec](IMPORTANT): platform_buoyancy_position 208.272034 cc
2022-12-14T19:32:40.755Z,1671046360.755 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:32:40.756Z,1671046360.756 [CommandExec](IMPORTANT): platform_buoyancy_position 208.272034 cc
2022-12-14T19:32:54.095Z,1671046374.095 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:32:54.096Z,1671046374.096 [CommandExec](IMPORTANT): platform_mass_position 0.015000 m
2022-12-14T19:33:28.146Z,1671046408.146 [CommandExec](IMPORTANT): got command get platform_buoyancy_position millimeter
2022-12-14T19:33:28.147Z,1671046408.147 [CommandExec](IMPORTANT): platform_buoyancy_position 0.208272 mm
2022-12-14T19:33:48.532Z,1671046428.532 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:33:48.532Z,1671046428.532 [CommandExec](IMPORTANT): platform_buoyancy_position 208.272034 cc
2022-12-14T19:34:07.026Z,1671046447.026 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:34:07.027Z,1671046447.027 [CommandExec](IMPORTANT): platform_mass_position 0.015000 m
2022-12-14T19:34:43.619Z,1671046483.619 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 20 millimeter
2022-12-14T19:34:49.360Z,1671046489.360 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:34:55.155Z,1671046495.155 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:34:55.159Z,1671046495.159 [CommandExec](IMPORTANT): platform_mass_position 0.020003 m
2022-12-14T19:35:20.064Z,1671046520.064 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:35:33.410Z,1671046533.410 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:35:33.410Z,1671046533.410 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:35:33.410Z,1671046533.410 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:35:33.410Z,1671046533.410 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:35:33.822Z,1671046533.822 [Default:CheckIn:D] Stopped
2022-12-14T19:35:33.823Z,1671046533.823 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.432878 min 
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn:E] Stopped
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn] Stopped
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn](INFO): Running loop #16
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn] Running Loop=16
2022-12-14T19:35:34.210Z,1671046534.210 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:35:34.211Z,1671046534.211 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:35:36.240Z,1671046536.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193535.00,A,3648.16390,N,12147.28248,W,0.505,0.00,141222,,,D*76
2022-12-14T19:35:36.242Z,1671046536.242 [NAL9602](INFO): GPS fix at 20221214T193535: (36.802732, -121.788041)
2022-12-14T19:35:36.253Z,1671046536.253 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:35:36.253Z,1671046536.253 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:35:43.507Z,1671046543.507 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0049.lzma
2022-12-14T19:35:44.509Z,1671046544.509 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0049.lzma.bak
2022-12-14T19:35:44.509Z,1671046544.509 [DataOverHttps](INFO): SBD MOMSN=17395551
2022-12-14T19:36:03.684Z,1671046563.684 [DataOverHttps](INFO): Sending 570 bytes from file Logs/20221214T175659/Express0050.lzma
2022-12-14T19:36:04.687Z,1671046564.687 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0050.lzma.bak
2022-12-14T19:36:04.687Z,1671046564.687 [DataOverHttps](INFO): SBD MOMSN=17395554
2022-12-14T19:36:06.933Z,1671046566.933 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:36:07.011Z,1671046567.011 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:36:07.364Z,1671046567.364 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:36:07.365Z,1671046567.365 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T19:36:07.365Z,1671046567.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:39:09.184Z,1671046749.184 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault 20 millimeter persist
2022-12-14T19:39:13.405Z,1671046753.405 [CommandExec](IMPORTANT): got command maintain clear
2022-12-14T19:39:13.733Z,1671046753.733 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,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,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-14T19:39:23.137Z,1671046763.137 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:39:23.138Z,1671046763.138 [CommandExec](IMPORTANT): platform_mass_position 0.020003 m
2022-12-14T19:39:37.365Z,1671046777.365 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:39:37.365Z,1671046777.365 [CommandExec](IMPORTANT): platform_buoyancy_position 468.142578 cc
2022-12-14T19:40:38.556Z,1671046838.556 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:40:38.881Z,1671046838.881 [CommandExec](IMPORTANT): got command get platform_buoyancy_position
2022-12-14T19:40:38.882Z,1671046838.882 [CommandExec](IMPORTANT): platform_buoyancy_position 947.459229 cc
2022-12-14T19:40:48.907Z,1671046848.907 [CommandExec](IMPORTANT): got command get platform_mass_position
2022-12-14T19:40:48.908Z,1671046848.908 [CommandExec](IMPORTANT): platform_mass_position 0.020003 m
2022-12-14T19:41:08.150Z,1671046868.150 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T19:41:08.150Z,1671046868.150 [Default:CheckIn:C.Wait] Stopped
2022-12-14T19:41:08.150Z,1671046868.150 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:41:08.150Z,1671046868.150 [Default:CheckIn:D] Running Loop=1
2022-12-14T19:41:08.577Z,1671046868.577 [Default:CheckIn:D] Stopped
2022-12-14T19:41:08.577Z,1671046868.577 [Default:CheckIn:E] Running Loop=1
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.012118 min 
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn:E] Stopped
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn] Stopped
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn](INFO): Running loop #17
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn] Running Loop=17
2022-12-14T19:41:08.972Z,1671046868.972 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T19:41:08.973Z,1671046868.973 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T19:41:09.333Z,1671046869.333 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:41:10.934Z,1671046870.934 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194110.00,A,3648.16456,N,12147.28025,W,0.233,0.00,141222,,,A*71
2022-12-14T19:41:10.937Z,1671046870.937 [NAL9602](INFO): GPS fix at 20221214T194110: (36.802743, -121.788004)
2022-12-14T19:41:10.972Z,1671046870.972 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T19:41:10.972Z,1671046870.972 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T19:41:19.870Z,1671046879.870 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0052.lzma
2022-12-14T19:41:22.370Z,1671046882.370 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0052.lzma.bak
2022-12-14T19:41:22.370Z,1671046882.370 [DataOverHttps](INFO): SBD MOMSN=17395573
2022-12-14T19:41:31.297Z,1671046891.297 [DataOverHttps](IMPORTANT): SBD MTMSN=20221214T194130
2022-12-14T19:41:38.723Z,1671046898.723 [DataOverHttps](INFO): Sending 406 bytes from file Logs/20221214T175659/Express0053.lzma
2022-12-14T19:41:38.727Z,1671046898.727 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-12-14T19:41:38.827Z,1671046898.827 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-14T19:41:38.827Z,1671046898.827 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-14T19:41:38.960Z,1671046898.960 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-12-14T19:41:38.963Z,1671046898.963 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-12-14T19:41:38.966Z,1671046898.966 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-12-14T19:41:38.969Z,1671046898.969 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-12-14T19:41:38.972Z,1671046898.972 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-12-14T19:41:38.974Z,1671046898.974 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-12-14T19:41:38.994Z,1671046898.994 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-12-14T19:41:38.997Z,1671046898.997 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-12-14T19:41:39.005Z,1671046899.005 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-12-14T19:41:39.009Z,1671046899.009 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-12-14T19:41:39.012Z,1671046899.012 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-12-14T19:41:39.020Z,1671046899.020 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-12-14T19:41:39.023Z,1671046899.023 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-12-14T19:41:39.030Z,1671046899.030 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-12-14T19:41:39.031Z,1671046899.031 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-12-14T19:41:39.444Z,1671046899.444 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-12-14T19:41:39.447Z,1671046899.447 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-12-14T19:41:39.450Z,1671046899.450 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-12-14T19:41:39.453Z,1671046899.453 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-12-14T19:41:39.455Z,1671046899.455 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-12-14T19:41:39.458Z,1671046899.458 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-12-14T19:41:39.461Z,1671046899.461 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-12-14T19:41:39.464Z,1671046899.464 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-12-14T19:41:39.467Z,1671046899.467 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-12-14T19:41:39.470Z,1671046899.470 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-12-14T19:41:39.472Z,1671046899.472 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-12-14T19:41:39.491Z,1671046899.491 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-12-14T19:41:39.494Z,1671046899.494 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-12-14T19:41:39.501Z,1671046899.501 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-12-14T19:41:39.515Z,1671046899.515 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-12-14T19:41:39.523Z,1671046899.523 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-12-14T19:41:39.526Z,1671046899.526 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-12-14T19:41:39.542Z,1671046899.542 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-12-14T19:41:39.549Z,1671046899.549 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-12-14T19:41:39.554Z,1671046899.554 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-12-14T19:41:39.569Z,1671046899.569 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2022-12-14T19:41:39.573Z,1671046899.573 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-12-14T19:41:39.584Z,1671046899.584 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-12-14T19:41:39.587Z,1671046899.587 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-12-14T19:41:39.598Z,1671046899.598 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-12-14T19:41:39.601Z,1671046899.601 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-12-14T19:41:39.604Z,1671046899.604 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-12-14T19:41:39.607Z,1671046899.607 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-12-14T19:41:39.628Z,1671046899.628 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-12-14T19:41:39.642Z,1671046899.642 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-12-14T19:41:39.673Z,1671046899.673 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-12-14T19:41:39.681Z,1671046899.681 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-12-14T19:41:39.704Z,1671046899.704 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-12-14T19:41:39.707Z,1671046899.707 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-12-14T19:41:39.740Z,1671046899.740 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-12-14T19:41:39.751Z,1671046899.751 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-12-14T19:41:39.754Z,1671046899.754 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-12-14T19:41:39.773Z,1671046899.773 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-12-14T19:41:39.780Z,1671046899.780 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-12-14T19:41:39.792Z,1671046899.792 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-12-14T19:41:39.795Z,1671046899.795 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-12-14T19:41:39.819Z,1671046899.819 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-12-14T19:41:39.822Z,1671046899.822 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-12-14T19:41:39.833Z,1671046899.833 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-12-14T19:41:39.849Z,1671046899.849 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-12-14T19:41:39.856Z,1671046899.856 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-12-14T19:41:39.875Z,1671046899.875 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-12-14T19:41:39.878Z,1671046899.878 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-12-14T19:41:39.889Z,1671046899.889 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-12-14T19:41:39.905Z,1671046899.905 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-12-14T19:41:39.912Z,1671046899.912 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-12-14T19:41:39.929Z,1671046899.929 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-12-14T19:41:39.948Z,1671046899.948 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-12-14T19:41:39.955Z,1671046899.955 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-12-14T19:41:39.958Z,1671046899.958 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-12-14T19:41:39.969Z,1671046899.969 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-12-14T19:41:39.981Z,1671046899.981 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-12-14T19:41:39.992Z,1671046899.992 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-12-14T19:41:40.007Z,1671046900.007 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-12-14T19:41:40.010Z,1671046900.010 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-12-14T19:41:40.022Z,1671046900.022 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-12-14T19:41:40.030Z,1671046900.030 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-12-14T19:41:40.069Z,1671046900.069 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-12-14T19:41:40.080Z,1671046900.080 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-12-14T19:41:40.099Z,1671046900.099 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-12-14T19:41:40.274Z,1671046900.274 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-14T19:41:40.293Z,1671046900.293 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0053.lzma.bak
2022-12-14T19:41:40.293Z,1671046900.293 [DataOverHttps](INFO): SBD MOMSN=17395577
2022-12-14T19:41:40.332Z,1671046900.332 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-14T19:41:40.365Z,1671046900.365 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-14T19:41:40.388Z,1671046900.388 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-14T19:41:40.410Z,1671046900.410 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-14T19:41:40.435Z,1671046900.435 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-14T19:41:40.495Z,1671046900.495 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-14T19:41:40.550Z,1671046900.550 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-14T19:41:40.570Z,1671046900.570 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-12-14T19:41:40.845Z,1671046900.845 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-12-14T19:41:40.854Z,1671046900.854 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-12-14T19:41:40.905Z,1671046900.905 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-12-14T19:41:40.919Z,1671046900.919 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-12-14T19:41:40.930Z,1671046900.930 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-12-14T19:41:40.965Z,1671046900.965 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-12-14T19:41:40.976Z,1671046900.976 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-12-14T19:41:40.987Z,1671046900.987 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-12-14T19:41:40.991Z,1671046900.991 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-12-14T19:41:41.002Z,1671046901.002 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-12-14T19:41:41.009Z,1671046901.009 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-12-14T19:41:41.036Z,1671046901.036 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-12-14T19:41:41.044Z,1671046901.044 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-12-14T19:41:41.055Z,1671046901.055 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-12-14T19:41:41.103Z,1671046901.103 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-12-14T19:41:41.115Z,1671046901.115 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-12-14T19:41:41.131Z,1671046901.131 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-12-14T19:41:41.165Z,1671046901.165 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-12-14T19:41:41.177Z,1671046901.177 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-12-14T19:41:41.192Z,1671046901.192 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-12-14T19:41:41.217Z,1671046901.217 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-12-14T19:41:41.228Z,1671046901.228 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-12-14T19:41:41.240Z,1671046901.240 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-12-14T19:41:41.299Z,1671046901.299 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-12-14T19:41:41.347Z,1671046901.347 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-12-14T19:41:41.393Z,1671046901.393 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-12-14T19:41:41.395Z,1671046901.395 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-12-14T19:41:41.405Z,1671046901.405 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-12-14T19:41:41.406Z,1671046901.406 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-12-14T19:41:41.424Z,1671046901.424 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-12-14T19:41:41.426Z,1671046901.426 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-12-14T19:41:41.444Z,1671046901.444 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-12-14T19:41:41.446Z,1671046901.446 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-12-14T19:41:41.477Z,1671046901.477 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-12-14T19:41:41.489Z,1671046901.489 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-12-14T19:41:41.590Z,1671046901.590 [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="ballast_and_trim">

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

    <DefineArg Name="SkipComms"><Description>
        Skip communications at start of mission.
    </Description><False/></DefineArg>

    <DefineArg Name="Depth1"><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="Depth2"><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed durnig the
        mission.
    </Description><Units:meter/><Value>0.1</Value></DefineArg>

    <DefineArg Name="SurfaceThreshold"><Description>
        Surface threshold depth.
    </Description><Units:meter/><Value>2.5</Value></DefineArg>

    <DefineArg Name="MaxWaitOnSurface"><Description>
        Maximum wait time for the vehicle to go under the surface (i.e., reach
        the surface threshold depth).
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait after reaching target depth before starting ballast and
        trim.
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="EstimationTimeout"><Description>
        Timeout for ballast and trim estimation.
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="MinEstimationTime"><Description>
        Minimum time to run ballast and trim estimation before determining
        convergence (must be shorter than timeout).
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="MassEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="BuoyEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:cubic_centimeter/><Value>15</Value></DefineArg>

    <DefineArg Name="EstimationConfidence"><Description>
        Confidence level that the estimator has reached the desired error range
        (larger values take longer to converge).
    </Description><Units:percent/><Value>99.9</Value></DefineArg>

    <DefineArg Name="WaitToFloat"><Units:minute/><Value>5</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

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

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

        <Insert Filename="Insert/BallastAndTrim.xml">
            <RedefineArg Name="InsertDepthDeadband"><Arg Name="DepthDeadband"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthTimeout"><Arg Name="MaxWaitOnSurface"/></RedefineArg>
            <RedefineArg Name="InsertSettleTime"><Arg Name="SettleTime"/></RedefineArg>
            <RedefineArg Name="EstTimeout"><Arg Name="EstimationTimeout"/></RedefineArg>
            <RedefineArg Name="MinEstTime"><Arg Name="MinEstimationTime"/></RedefineArg>
            <RedefineArg Name="MassEstErrorBound"><Arg Name="MassEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="BuoyEstErrorBound"><Arg Name="BuoyEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="EstConfidence"><Arg Name="EstimationConfidence"/></RedefineArg>
        </Insert>

        <Aggregate Id="Depth1">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth1"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth2"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

        <Description>
            Float to surface instead of driving.
        </Description>

        <Sequence/>

        <Break>
            <Universal:depth/>
            <Lt><Control:VerticalControl.surfaceThreshold/></Lt>
        </Break>

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

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="WaitToFloat"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2022-12-14T19:41:41.601Z,1671046901.601 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-14T19:41:41.688Z,1671046901.688 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T19:41:41.771Z,1671046901.771 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T19:41:41.820Z,1671046901.820 [Default] Stopped
2022-12-14T19:41:41.820Z,1671046901.820 [Default](DEBUG): Aggregate::uninitialize Default
2022-12-14T19:41:41.820Z,1671046901.820 [Default:B.GoToSurface] Stopped
2022-12-14T19:41:41.820Z,1671046901.820 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-14T19:41:41.820Z,1671046901.820 [Default:CheckIn] Stopped
2022-12-14T19:41:41.820Z,1671046901.820 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T19:41:41.820Z,1671046901.820 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T19:41:41.821Z,1671046901.821 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science:A] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science:B] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science:C] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science:D] Running Loop=1
2022-12-14T19:41:41.821Z,1671046901.821 [ballast_and_trim:Science:E] Running Loop=1
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:F] Running Loop=1
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-12-14T19:41:41.822Z,1671046901.822 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-14T19:41:41.828Z,1671046901.828 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-12-14T19:41:41.829Z,1671046901.829 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-12-14T19:41:41.830Z,1671046901.830 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-14T19:41:41.840Z,1671046901.840 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-12-14T19:41:41.840Z,1671046901.840 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-12-14T19:41:41.840Z,1671046901.840 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-12-14T19:41:41.840Z,1671046901.840 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-14T19:41:41.842Z,1671046901.842 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-12-14T19:41:41.842Z,1671046901.842 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-12-14T19:41:41.842Z,1671046901.842 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-14T19:41:41.842Z,1671046901.842 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-14T19:41:41.843Z,1671046901.843 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-12-14T19:41:41.843Z,1671046901.843 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-12-14T19:41:41.859Z,1671046901.859 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-12-14T19:41:41.859Z,1671046901.859 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-14T19:41:41.869Z,1671046901.869 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-12-14T19:41:41.869Z,1671046901.869 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-12-14T19:41:41.869Z,1671046901.869 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-12-14T19:41:41.869Z,1671046901.869 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-14T19:41:41.871Z,1671046901.871 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-12-14T19:41:41.871Z,1671046901.871 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-12-14T19:41:41.875Z,1671046901.875 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-14T19:41:41.875Z,1671046901.875 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-12-14T19:41:41.876Z,1671046901.876 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-12-14T19:41:41.877Z,1671046901.877 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-12-14T19:41:41.877Z,1671046901.877 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-14T19:41:41.877Z,1671046901.877 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-12-14T19:41:41.878Z,1671046901.878 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-12-14T19:41:41.878Z,1671046901.878 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-12-14T19:41:41.878Z,1671046901.878 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-14T19:41:41.878Z,1671046901.878 [ballast_and_trim:Science] Running Loop=1
2022-12-14T19:41:41.887Z,1671046901.887 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-12-14T19:41:41.887Z,1671046901.887 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-12-14T19:41:41.888Z,1671046901.888 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-14T19:41:41.889Z,1671046901.889 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:Read_Oil] Stopped
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:F] Stopped
2022-12-14T19:41:41.890Z,1671046901.890 [ballast_and_trim:Science:E] Running Loop=1
2022-12-14T19:41:41.897Z,1671046901.897 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-12-14T19:41:41.897Z,1671046901.897 [ballast_and_trim:Science:D] Stopped
2022-12-14T19:41:41.897Z,1671046901.897 [ballast_and_trim:Science:C] Running Loop=1
2022-12-14T19:41:41.898Z,1671046901.898 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-12-14T19:41:41.898Z,1671046901.898 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-12-14T19:41:41.898Z,1671046901.898 [ballast_and_trim:Science:B] Running Loop=1
2022-12-14T19:41:41.903Z,1671046901.903 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-12-14T19:41:41.904Z,1671046901.904 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-12-14T19:41:41.904Z,1671046901.904 [ballast_and_trim:Science:A] Stopped
2022-12-14T19:41:41.952Z,1671046901.952 [WetLabsBB2FL](INFO): Powering up
2022-12-14T19:41:42.143Z,1671046902.143 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-12-14T19:41:42.143Z,1671046902.143 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-12-14T19:41:42.144Z,1671046902.144 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-12-14T19:41:42.146Z,1671046902.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-12-14T19:41:42.147Z,1671046902.147 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-12-14T19:41:42.155Z,1671046902.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-12-14T19:41:42.155Z,1671046902.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-12-14T19:41:42.155Z,1671046902.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-12-14T19:41:42.155Z,1671046902.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-12-14T19:41:42.156Z,1671046902.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-12-14T19:41:42.157Z,1671046902.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-12-14T19:41:42.157Z,1671046902.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-12-14T19:41:42.529Z,1671046902.529 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-12-14T19:41:42.530Z,1671046902.530 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-12-14T19:41:42.530Z,1671046902.530 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-12-14T19:41:42.530Z,1671046902.530 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-12-14T19:41:42.530Z,1671046902.530 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-12-14T19:41:42.932Z,1671046902.932 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-12-14T19:41:42.932Z,1671046902.932 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-12-14T19:41:42.932Z,1671046902.932 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-12-14T19:41:42.933Z,1671046902.933 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-12-14T19:41:43.340Z,1671046903.340 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-12-14T19:41:43.341Z,1671046903.341 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-12-14T19:41:43.341Z,1671046903.341 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-12-14T19:41:43.341Z,1671046903.341 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-12-14T19:41:43.341Z,1671046903.341 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-12-14T19:41:45.060Z,1671046905.060 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-12-14T19:42:28.595Z,1671046948.595 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221214T175659/Courier0055.lzma
2022-12-14T19:42:29.597Z,1671046949.597 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0055.lzma.bak
2022-12-14T19:42:29.597Z,1671046949.597 [DataOverHttps](INFO): SBD MOMSN=17395592
2022-12-14T19:43:23.823Z,1671047003.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T19:43:29.848Z,1671047009.848 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251163
2022-12-14T19:43:38.295Z,1671047018.295 [Radio_Surface](INFO): Powering down
2022-12-14T19:43:38.883Z,1671047018.883 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-12-14T19:44:23.379Z,1671047063.379 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-12-14T19:44:23.379Z,1671047063.379 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-14T19:44:23.380Z,1671047063.380 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-12-14T19:44:23.381Z,1671047063.381 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-12-14T19:44:23.784Z,1671047063.784 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.046985 m 
2022-12-14T19:44:23.784Z,1671047063.784 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-12-14T19:44:23.784Z,1671047063.784 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-12-14T19:44:23.784Z,1671047063.784 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-12-14T19:44:23.785Z,1671047063.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-12-14T19:44:23.785Z,1671047063.785 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-12-14T19:46:13.249Z,1671047173.249 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T19:46:43.957Z,1671047203.957 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T19:54:24.542Z,1671047664.542 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-12-14T19:54:24.542Z,1671047664.542 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-12-14T19:54:24.542Z,1671047664.542 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T19:54:24.543Z,1671047664.543 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-12-14T19:54:24.958Z,1671047664.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 6.974970 m 
2022-12-14T19:54:24.958Z,1671047664.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-12-14T19:54:24.958Z,1671047664.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-12-14T19:54:24.958Z,1671047664.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-12-14T20:14:29.293Z,1671048869.293 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:14:42.619Z,1671048882.619 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:14:55.953Z,1671048895.953 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:15:09.284Z,1671048909.284 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:15:23.020Z,1671048923.020 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:15:36.354Z,1671048936.354 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:15:50.088Z,1671048950.088 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:16:04.227Z,1671048964.227 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:16:17.562Z,1671048977.562 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:16:30.487Z,1671048990.487 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:16:44.223Z,1671049004.223 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-14T20:19:24.634Z,1671049164.634 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 5.
2022-12-14T20:19:24.641Z,1671049164.641 [BPC1](INFO): Received data from all battery sticks.
2022-12-14T20:39:25.754Z,1671050365.754 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](FAULT): BallastAndTrim completed. Values did not meet error bound requirements requested by user. Will NOT write estimation values to config! Estimation time: 45.01 minutes (time-out limit reached).
2022-12-14T20:39:25.755Z,1671050365.755 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 339.205764 +/- 8.452184 cc (conf. level 99.90%, sigma: 21.298696 cc).
2022-12-14T20:39:25.772Z,1671050365.772 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 13.497905 +/- 0.251562 mm (conf. level 99.90%, sigma: 0.633912 mm).
2022-12-14T20:39:25.772Z,1671050365.772 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-12-14T20:39:25.772Z,1671050365.772 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-12-14T20:39:25.773Z,1671050365.773 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-14T20:39:25.773Z,1671050365.773 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-12-14T20:39:25.773Z,1671050365.773 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-14T20:39:25.773Z,1671050365.773 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-12-14T20:39:25.774Z,1671050365.774 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-12-14T20:39:25.774Z,1671050365.774 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-12-14T20:39:25.775Z,1671050365.775 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-12-14T20:39:26.158Z,1671050366.158 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-14T20:39:26.158Z,1671050366.158 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-12-14T20:39:26.158Z,1671050366.158 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-12-14T20:39:26.159Z,1671050366.159 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2022-12-14T20:39:26.566Z,1671050366.566 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-12-14T20:39:26.567Z,1671050366.567 [ballast_and_trim:Float_Up] Running Loop=1
2022-12-14T20:39:26.568Z,1671050366.568 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2022-12-14T20:39:26.568Z,1671050366.568 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-12-14T20:39:26.568Z,1671050366.568 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-12-14T20:39:26.568Z,1671050366.568 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2022-12-14T20:39:26.568Z,1671050366.568 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2022-12-14T20:39:26.960Z,1671050366.960 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up] Stopped
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up:B.Wait] Stopped
2022-12-14T20:41:03.114Z,1671050463.114 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T20:41:03.116Z,1671050463.116 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-12-14T20:41:03.116Z,1671050463.116 [MissionManager](INFO): ballast_and_trim is completed.
2022-12-14T20:41:03.116Z,1671050463.116 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-12-14T20:41:03.116Z,1671050463.116 [ballast_and_trim] Stopped
2022-12-14T20:41:03.116Z,1671050463.116 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-12-14T20:41:03.116Z,1671050463.116 [ballast_and_trim:Science] Stopped
2022-12-14T20:41:03.116Z,1671050463.116 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:B] Stopped
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:C] Stopped
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:E] Stopped
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-12-14T20:41:03.117Z,1671050463.117 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-12-14T20:41:03.347Z,1671050463.347 [WetLabsBB2FL](INFO): Powering down
2022-12-14T20:41:03.526Z,1671050463.526 [MissionManager](IMPORTANT): Started mission Default
2022-12-14T20:41:03.526Z,1671050463.526 [Default] Running Loop=1
2022-12-14T20:41:03.526Z,1671050463.526 [Default](DEBUG): Aggregate::initialize Default
2022-12-14T20:41:03.526Z,1671050463.526 [Default:B.GoToSurface] Running Loop=1
2022-12-14T20:41:03.526Z,1671050463.526 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-14T20:41:03.527Z,1671050463.527 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-14T20:41:03.527Z,1671050463.527 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-14T20:41:03.527Z,1671050463.527 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-14T20:41:03.528Z,1671050463.528 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-14T20:41:03.528Z,1671050463.528 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-14T20:41:03.528Z,1671050463.528 [Default:A.Wait] Running Loop=1
2022-12-14T20:41:03.528Z,1671050463.528 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-14T20:41:03.735Z,1671050463.735 [Radio_Surface](INFO): Powering up
2022-12-14T20:41:09.155Z,1671050469.155 [DataOverHttps](INFO): Radio surface powered ON.
2022-12-14T20:41:16.855Z,1671050476.855 [Default:A.Wait](INFO): Done Waiting.
2022-12-14T20:41:16.855Z,1671050476.855 [Default:A.Wait] Stopped
2022-12-14T20:41:16.855Z,1671050476.855 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T20:41:17.263Z,1671050477.263 [Default:CheckIn] Running Loop=1
2022-12-14T20:41:17.263Z,1671050477.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T20:41:17.263Z,1671050477.263 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T20:41:39.276Z,1671050499.276 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T20:41:49.965Z,1671050509.965 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T20:41:50.047Z,1671050510.047 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T20:42:14.415Z,1671050534.415 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T20:42:49.573Z,1671050569.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T20:43:24.711Z,1671050604.711 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T20:43:59.851Z,1671050639.851 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-14T20:44:33.455Z,1671050673.455 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003071
2022-12-14T20:46:17.449Z,1671050777.449 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-14T20:41:17.3Z
2022-12-14T20:46:17.449Z,1671050777.449 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T20:46:17.449Z,1671050777.449 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T20:46:21.491Z,1671050781.491 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T20:46:29.199Z,1671050789.199 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20221214T175659/Courier0058.lzma
2022-12-14T20:46:30.201Z,1671050790.201 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0058.lzma.bak
2022-12-14T20:46:30.202Z,1671050790.202 [DataOverHttps](INFO): SBD MOMSN=17395628
2022-12-14T20:46:48.207Z,1671050808.207 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221214T175659/Express0056.lzma
2022-12-14T20:46:49.209Z,1671050809.209 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0056.lzma.bak
2022-12-14T20:46:49.209Z,1671050809.209 [DataOverHttps](INFO): SBD MOMSN=17395630
2022-12-14T20:46:52.248Z,1671050812.248 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T20:47:08.936Z,1671050828.936 [DataOverHttps](INFO): Sending 1032 bytes from file Logs/20221214T175659/Express0059.lzma
2022-12-14T20:47:09.937Z,1671050829.937 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0059.lzma.bak
2022-12-14T20:47:09.938Z,1671050829.938 [DataOverHttps](INFO): SBD MOMSN=17395634
2022-12-14T20:47:15.762Z,1671050835.762 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T20:47:15.763Z,1671050835.763 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T20:47:15.767Z,1671050835.767 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T20:52:16.317Z,1671051136.317 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T20:52:16.317Z,1671051136.317 [Default:CheckIn:C.Wait] Stopped
2022-12-14T20:52:16.317Z,1671051136.317 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T20:52:16.317Z,1671051136.317 [Default:CheckIn:D] Running Loop=1
2022-12-14T20:52:16.722Z,1671051136.722 [Default:CheckIn:D] Stopped
2022-12-14T20:52:16.722Z,1671051136.722 [Default:CheckIn:E] Running Loop=1
2022-12-14T20:52:17.149Z,1671051137.149 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.219930 min 
2022-12-14T20:52:17.149Z,1671051137.149 [Default:CheckIn:E] Stopped
2022-12-14T20:52:17.149Z,1671051137.149 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T20:52:17.149Z,1671051137.149 [Default:CheckIn] Stopped
2022-12-14T20:52:17.150Z,1671051137.150 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T20:52:17.150Z,1671051137.150 [Default:CheckIn](INFO): Running loop #2
2022-12-14T20:52:17.150Z,1671051137.150 [Default:CheckIn] Running Loop=2
2022-12-14T20:52:17.150Z,1671051137.150 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T20:52:17.150Z,1671051137.150 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T20:52:18.733Z,1671051138.733 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-14T20:52:18.733Z,1671051138.733 [NAL9602] Data Fault, FailCount= 2
2022-12-14T20:52:18.733Z,1671051138.733 [NAL9602](ERROR): Data Fault
2022-12-14T20:52:18.761Z,1671051138.761 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-14T20:52:19.136Z,1671051139.136 [NAL9602](INFO): Powering down
2022-12-14T20:52:19.971Z,1671051139.971 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-14T20:52:19.971Z,1671051139.971 [NAL9602] No Fault, FailCount= 2
2022-12-14T20:52:49.441Z,1671051169.441 [NAL9602](INFO): Powering up NAL9602
2022-12-14T20:53:00.345Z,1671051180.345 [NAL9602](INFO): NAL9602 initialized
2022-12-14T20:57:17.406Z,1671051437.406 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-14T20:52:17.1Z
2022-12-14T20:57:17.406Z,1671051437.406 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T20:57:17.407Z,1671051437.407 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T20:57:25.399Z,1671051445.399 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221214T175659/Courier0061.lzma
2022-12-14T20:57:26.401Z,1671051446.401 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0061.lzma.bak
2022-12-14T20:57:26.401Z,1671051446.401 [DataOverHttps](INFO): SBD MOMSN=17395645
2022-12-14T20:57:44.940Z,1671051464.940 [DataOverHttps](INFO): Sending 466 bytes from file Logs/20221214T175659/Express0062.lzma
2022-12-14T20:57:45.941Z,1671051465.941 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0062.lzma.bak
2022-12-14T20:57:45.941Z,1671051465.941 [DataOverHttps](INFO): SBD MOMSN=17395647
2022-12-14T20:57:48.587Z,1671051468.587 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T20:57:48.587Z,1671051468.587 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T20:57:48.587Z,1671051468.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T20:58:03.912Z,1671051483.912 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T20:58:34.615Z,1671051514.615 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T21:02:49.194Z,1671051769.194 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T21:02:49.194Z,1671051769.194 [Default:CheckIn:C.Wait] Stopped
2022-12-14T21:02:49.195Z,1671051769.195 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T21:02:49.195Z,1671051769.195 [Default:CheckIn:D] Running Loop=1
2022-12-14T21:02:49.604Z,1671051769.604 [Default:CheckIn:D] Stopped
2022-12-14T21:02:49.604Z,1671051769.604 [Default:CheckIn:E] Running Loop=1
2022-12-14T21:02:50.022Z,1671051770.022 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.767959 min 
2022-12-14T21:02:50.022Z,1671051770.022 [Default:CheckIn:E] Stopped
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn] Stopped
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn](INFO): Running loop #3
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn] Running Loop=3
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T21:02:50.023Z,1671051770.023 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T21:02:52.005Z,1671051772.005 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210250.00,A,3648.16864,N,12147.28036,W,0.194,190.80,141222,,,A*78
2022-12-14T21:02:52.008Z,1671051772.008 [NAL9602](INFO): GPS fix at 20221214T210250: (36.802811, -121.788006)
2022-12-14T21:02:52.018Z,1671051772.018 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T21:02:52.018Z,1671051772.018 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T21:02:59.423Z,1671051779.423 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221214T175659/Courier0064.lzma
2022-12-14T21:03:00.425Z,1671051780.425 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0064.lzma.bak
2022-12-14T21:03:00.425Z,1671051780.425 [DataOverHttps](INFO): SBD MOMSN=17395653
2022-12-14T21:03:22.023Z,1671051802.023 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221214T175659/Express0065.lzma
2022-12-14T21:03:22.429Z,1671051802.429 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T21:03:22.511Z,1671051802.511 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T21:03:23.025Z,1671051803.025 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0065.lzma.bak
2022-12-14T21:03:23.025Z,1671051803.025 [DataOverHttps](INFO): SBD MOMSN=17395659
2022-12-14T21:03:25.708Z,1671051805.708 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T21:03:25.709Z,1671051805.709 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T21:03:25.709Z,1671051805.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T21:07:54.379Z,1671052074.379 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T21:08:25.138Z,1671052105.138 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T21:08:26.415Z,1671052106.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T21:08:26.415Z,1671052106.415 [Default:CheckIn:C.Wait] Stopped
2022-12-14T21:08:26.415Z,1671052106.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T21:08:26.416Z,1671052106.416 [Default:CheckIn:D] Running Loop=1
2022-12-14T21:08:26.841Z,1671052106.841 [Default:CheckIn:D] Stopped
2022-12-14T21:08:26.841Z,1671052106.841 [Default:CheckIn:E] Running Loop=1
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.388574 min 
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn:E] Stopped
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn] Stopped
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn](INFO): Running loop #4
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn] Running Loop=4
2022-12-14T21:08:27.228Z,1671052107.228 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T21:08:27.229Z,1671052107.229 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T21:08:29.194Z,1671052109.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210828.00,A,3648.16856,N,12147.27557,W,0.447,190.80,141222,,,A*7A
2022-12-14T21:08:29.196Z,1671052109.196 [NAL9602](INFO): GPS fix at 20221214T210828: (36.802809, -121.787926)
2022-12-14T21:08:29.225Z,1671052109.225 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T21:08:29.225Z,1671052109.225 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-14T21:08:38.571Z,1671052118.571 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221214T175659/Courier0067.lzma
2022-12-14T21:08:39.573Z,1671052119.573 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Courier0067.lzma.bak
2022-12-14T21:08:39.573Z,1671052119.573 [DataOverHttps](INFO): SBD MOMSN=17395688
2022-12-14T21:08:56.699Z,1671052136.699 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20221214T175659/Express0068.lzma
2022-12-14T21:08:57.701Z,1671052137.701 [DataOverHttps](INFO): Moved sent file to Logs/20221214T175659/Express0068.lzma.bak
2022-12-14T21:08:57.701Z,1671052137.701 [DataOverHttps](INFO): SBD MOMSN=17395692
2022-12-14T21:08:59.997Z,1671052139.997 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T21:09:00.071Z,1671052140.071 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T21:09:00.443Z,1671052140.443 [Default:CheckIn:Read_Iridium] Stopped
2022-12-14T21:09:00.447Z,1671052140.447 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-14T21:09:00.447Z,1671052140.447 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-14T21:13:31.557Z,1671052411.557 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-14T21:14:01.066Z,1671052441.066 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-14T21:14:01.066Z,1671052441.066 [Default:CheckIn:C.Wait] Stopped
2022-12-14T21:14:01.066Z,1671052441.066 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-14T21:14:01.067Z,1671052441.067 [Default:CheckIn:D] Running Loop=1
2022-12-14T21:14:01.479Z,1671052441.479 [Default:CheckIn:D] Stopped
2022-12-14T21:14:01.479Z,1671052441.479 [Default:CheckIn:E] Running Loop=1
2022-12-14T21:14:01.872Z,1671052441.872 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.965873 min 
2022-12-14T21:14:01.872Z,1671052441.872 [Default:CheckIn:E] Stopped
2022-12-14T21:14:01.872Z,1671052441.872 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-14T21:14:01.872Z,1671052441.872 [Default:CheckIn] Stopped
2022-12-14T21:14:01.872Z,1671052441.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T21:14:01.873Z,1671052441.873 [Default:CheckIn](INFO): Running loop #5
2022-12-14T21:14:01.873Z,1671052441.873 [Default:CheckIn] Running Loop=5
2022-12-14T21:14:01.873Z,1671052441.873 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-14T21:14:01.873Z,1671052441.873 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-14T21:14:02.260Z,1671052442.260 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-14T21:14:34.576Z,1671052474.576 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-14T21:14:34.659Z,1671052474.659 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-14T21:15:40.608Z,1671052540.608 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.147251
2022-12-14T21:15:50.060Z,1671052550.060 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003309
2022-12-14T21:16:42.056Z,1671052602.056 [CommandExec](IMPORTANT): got command quit
2022-12-14T21:16:43.059Z,1671052603.059 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-12-14T21:16:43.059Z,1671052603.059 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:43.060Z,1671052603.060 [CommandExec](INFO): Uninitializing the command executive.
2022-12-14T21:16:43.060Z,1671052603.060 [CommandExec](INFO): Uninitializing the command scheduler.
2022-12-14T21:16:43.060Z,1671052603.060 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.060Z,1671052603.060 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-12-14T21:16:43.061Z,1671052603.061 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-12-14T21:16:43.061Z,1671052603.061 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.062Z,1671052603.062 [NavChartDb](INFO): Join timeout helper Thread ID is 493
2022-12-14T21:16:43.163Z,1671052603.163 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:43.164Z,1671052603.164 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.183Z,1671052603.183 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-12-14T21:16:43.183Z,1671052603.183 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.184Z,1671052603.184 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 494
2022-12-14T21:16:43.432Z,1671052603.432 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:43.432Z,1671052603.432 [WetLabsBB2FL](INFO): Powering down
2022-12-14T21:16:43.433Z,1671052603.433 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.435Z,1671052603.435 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-12-14T21:16:43.435Z,1671052603.435 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:43.436Z,1671052603.436 [CTD_Seabird](INFO): Join timeout helper Thread ID is 495
2022-12-14T21:16:44.123Z,1671052604.123 [CTD_Seabird](INFO): Powering down
2022-12-14T21:16:44.135Z,1671052604.135 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:44.135Z,1671052604.135 [CTD_Seabird](INFO): Powering down
2022-12-14T21:16:44.147Z,1671052604.147 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.147Z,1671052604.147 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-12-14T21:16:44.148Z,1671052604.148 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.148Z,1671052604.148 [DAT](INFO): Join timeout helper Thread ID is 496
2022-12-14T21:16:44.203Z,1671052604.203 [DAT](INFO): Powering down
2022-12-14T21:16:44.295Z,1671052604.295 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:44.296Z,1671052604.296 [DAT](INFO): Powering down
2022-12-14T21:16:44.296Z,1671052604.296 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.315Z,1671052604.315 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-12-14T21:16:44.315Z,1671052604.315 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.316Z,1671052604.316 [Radio_Surface](INFO): Join timeout helper Thread ID is 497
2022-12-14T21:16:44.415Z,1671052604.415 [Radio_Surface](INFO): Powering down
2022-12-14T21:16:44.416Z,1671052604.416 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:44.417Z,1671052604.417 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.420Z,1671052604.420 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-12-14T21:16:44.420Z,1671052604.420 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:44.421Z,1671052604.421 [Onboard](INFO): Join timeout helper Thread ID is 498
2022-12-14T21:16:44.603Z,1671052604.603 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-12-14T21:16:46.275Z,1671052606.275 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:46.276Z,1671052606.276 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.280Z,1671052606.280 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-12-14T21:16:46.280Z,1671052606.280 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.280Z,1671052606.280 [DataOverHttps](INFO): Join timeout helper Thread ID is 499
2022-12-14T21:16:46.611Z,1671052606.611 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:46.611Z,1671052606.611 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.625Z,1671052606.625 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-12-14T21:16:46.625Z,1671052606.625 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.626Z,1671052606.626 [BackseatComponent](INFO): Join timeout helper Thread ID is 500
2022-12-14T21:16:46.679Z,1671052606.679 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:46.680Z,1671052606.680 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.696Z,1671052606.696 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-12-14T21:16:46.696Z,1671052606.696 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.696Z,1671052606.696 [logger](INFO): Join timeout helper Thread ID is 501
2022-12-14T21:16:46.723Z,1671052606.723 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:46.724Z,1671052606.724 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.736Z,1671052606.736 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-12-14T21:16:46.737Z,1671052606.737 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.737Z,1671052606.737 [CommandLine](INFO): Join timeout helper Thread ID is 502
2022-12-14T21:16:46.831Z,1671052606.831 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:46.831Z,1671052606.831 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.848Z,1671052606.848 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-12-14T21:16:46.848Z,1671052606.848 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.848Z,1671052606.848 [CommandExec](INFO): Join timeout helper Thread ID is 503
2022-12-14T21:16:46.849Z,1671052606.849 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-12-14T21:16:46.849Z,1671052606.849 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:46.850Z,1671052606.850 [controlThread](INFO): Join timeout helper Thread ID is 504
2022-12-14T21:16:47.103Z,1671052607.103 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-14T21:16:47.103Z,1671052607.103 [controlThread](DEBUG): Uninitializing ControlThread
2022-12-14T21:16:47.104Z,1671052607.104 [AHRS_M2](INFO): Powering down
2022-12-14T21:16:47.176Z,1671052607.176 [NAL9602](INFO): Powering down
2022-12-14T21:16:47.178Z,1671052607.178 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-12-14T21:16:47.178Z,1671052607.178 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-12-14T21:16:47.179Z,1671052607.179 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-12-14T21:16:47.180Z,1671052607.180 [MissionManager](INFO): Uninitializing Mission Default
2022-12-14T21:16:47.180Z,1671052607.180 [Default] Stopped
2022-12-14T21:16:47.180Z,1671052607.180 [Default](DEBUG): Aggregate::uninitialize Default
2022-12-14T21:16:47.180Z,1671052607.180 [Default:B.GoToSurface] Stopped
2022-12-14T21:16:47.180Z,1671052607.180 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-14T21:16:47.180Z,1671052607.180 [Default:CheckIn] Stopped
2022-12-14T21:16:47.180Z,1671052607.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-14T21:16:47.180Z,1671052607.180 [Default:CheckIn:Read_GPS] Stopped
2022-12-14T21:16:47.183Z,1671052607.183 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-12-14T21:16:47.183Z,1671052607.183 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-12-14T21:16:47.184Z,1671052607.184 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-12-14T21:16:47.184Z,1671052607.184 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-12-14T21:16:47.184Z,1671052607.184 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-12-14T21:16:47.184Z,1671052607.184 [BuoyancyServo](INFO): Powering down
2022-12-14T21:16:47.199Z,1671052607.199 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-12-14T21:16:47.199Z,1671052607.199 [ElevatorServo](INFO): Powering down
2022-12-14T21:16:47.200Z,1671052607.200 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-12-14T21:16:47.200Z,1671052607.200 [MassServo](INFO): Powering down
2022-12-14T21:16:47.201Z,1671052607.201 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-14T21:16:47.201Z,1671052607.201 [RudderServo](INFO): Powering down
2022-12-14T21:16:47.202Z,1671052607.202 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-12-14T21:16:47.202Z,1671052607.202 [ThrusterHE](INFO): Powering down
2022-12-14T21:16:47.203Z,1671052607.203 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-12-14T21:16:47.203Z,1671052607.203 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-12-14T21:16:47.204Z,1671052607.204 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-12-14T21:16:47.204Z,1671052607.204 [CBIT](DEBUG): Powering off loads.
2022-12-14T21:16:47.215Z,1671052607.215 [CBIT](DEBUG): Disabling WDT.
2022-12-14T21:16:47.227Z,1671052607.227 [CBIT](DEBUG): Opening all GF detection circuits.
2022-12-14T21:16:47.228Z,1671052607.228 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.287Z,1671052607.287 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.292Z,1671052607.292 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.294Z,1671052607.294 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.301Z,1671052607.301 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.346Z,1671052607.346 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.382Z,1671052607.382 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.385Z,1671052607.385 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.417Z,1671052607.417 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-14T21:16:47.489Z,1671052607.489 [logger ThreadHandler](INFO): Thread cancelled.