2024-01-18T21:34:54.236Z,1705613694.236 [Supervisor](DEBUG): Initializing supervisor.
2024-01-18T21:34:54.240Z,1705613694.240 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-01-18T21:34:54.240Z,1705613694.240 [SyncHandler](INFO): Protected caller Thread ID is 6660
2024-01-18T21:34:54.241Z,1705613694.241 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-01-18T21:34:54.242Z,1705613694.242 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-01-18T21:34:54.242Z,1705613694.242 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6661
2024-01-18T21:34:54.246Z,1705613694.246 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-01-18T21:34:54.263Z,1705613694.263 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-01-18T21:34:54.264Z,1705613694.264 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-01-18T21:34:54.264Z,1705613694.264 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6662
2024-01-18T21:34:54.269Z,1705613694.269 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-01-18T21:34:54.270Z,1705613694.270 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-01-18T21:34:54.270Z,1705613694.270 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6663
2024-01-18T21:34:54.272Z,1705613694.272 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-01-18T21:34:54.273Z,1705613694.273 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-01-18T21:34:54.273Z,1705613694.273 [logger ThreadHandler](INFO): Protected caller Thread ID is 6664
2024-01-18T21:34:54.278Z,1705613694.278 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-01-18T21:34:54.278Z,1705613694.278 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-01-18T21:34:54.284Z,1705613694.284 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-01-18T21:34:54.650Z,1705613694.650 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-01-18T21:34:54.652Z,1705613694.652 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-01-18T21:34:54.737Z,1705613694.737 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-01-18T21:34:55.223Z,1705613695.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-01-18T21:34:55.225Z,1705613695.225 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-01-18T21:34:55.557Z,1705613695.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-01-18T21:34:55.559Z,1705613695.559 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-01-18T21:34:55.658Z,1705613695.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-01-18T21:34:55.660Z,1705613695.660 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-01-18T21:34:56.064Z,1705613696.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-01-18T21:34:56.066Z,1705613696.066 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-01-18T21:34:56.286Z,1705613696.286 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-01-18T21:34:56.286Z,1705613696.286 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-01-18T21:34:56.806Z,1705613696.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-01-18T21:34:56.807Z,1705613696.807 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-01-18T21:34:56.947Z,1705613696.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-01-18T21:34:56.949Z,1705613696.949 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-01-18T21:34:57.032Z,1705613697.032 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-01-18T21:34:57.976Z,1705613697.976 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-01-18T21:34:57.977Z,1705613697.977 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-01-18T21:34:58.831Z,1705613698.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-01-18T21:34:58.832Z,1705613698.832 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-01-18T21:34:59.024Z,1705613699.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-01-18T21:34:59.025Z,1705613699.025 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-01-18T21:34:59.139Z,1705613699.139 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-01-18T21:34:59.141Z,1705613699.141 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-01-18T21:34:59.373Z,1705613699.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-01-18T21:34:59.374Z,1705613699.374 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-01-18T21:34:59.632Z,1705613699.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-01-18T21:34:59.634Z,1705613699.634 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2024-01-18T21:34:59.638Z,1705613699.638 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2024-01-18T21:34:59.734Z,1705613699.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2024-01-18T21:34:59.823Z,1705613699.823 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2024-01-18T21:34:59.929Z,1705613699.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2024-01-18T21:35:00.016Z,1705613700.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2024-01-18T21:35:00.122Z,1705613700.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2024-01-18T21:35:00.227Z,1705613700.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2024-01-18T21:35:00.344Z,1705613700.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2024-01-18T21:35:00.424Z,1705613700.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2024-01-18T21:35:00.580Z,1705613700.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2024-01-18T21:35:00.726Z,1705613700.726 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2024-01-18T21:35:00.841Z,1705613700.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2024-01-18T21:35:01.111Z,1705613701.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-01-18T21:35:01.112Z,1705613701.112 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2024-01-18T21:35:01.113Z,1705613701.113 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2024-01-18T21:35:01.127Z,1705613701.127 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-01-18T21:35:01.196Z,1705613701.196 [VerticalControl](DEBUG): Construct VerticalControl.
2024-01-18T21:35:01.254Z,1705613701.254 [VerticalControl] Loaded
2024-01-18T21:35:01.254Z,1705613701.254 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-01-18T21:35:01.257Z,1705613701.257 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-01-18T21:35:01.297Z,1705613701.297 [HorizontalControl] Loaded
2024-01-18T21:35:01.297Z,1705613701.297 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-01-18T21:35:01.299Z,1705613701.299 [SpeedControl](DEBUG): Construct SpeedControl.
2024-01-18T21:35:01.302Z,1705613701.302 [SpeedControl] Loaded
2024-01-18T21:35:01.302Z,1705613701.302 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-01-18T21:35:01.305Z,1705613701.305 [LoopControl](DEBUG): Construct LoopControl.
2024-01-18T21:35:01.306Z,1705613701.306 [LoopControl] Loaded
2024-01-18T21:35:01.306Z,1705613701.306 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-01-18T21:35:01.306Z,1705613701.306 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-01-18T21:35:01.307Z,1705613701.307 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-01-18T21:35:01.323Z,1705613701.323 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-01-18T21:35:01.323Z,1705613701.323 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-01-18T21:35:01.502Z,1705613701.502 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-01-18T21:35:01.503Z,1705613701.503 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-01-18T21:35:01.660Z,1705613701.660 [BuoyancyServo] Loaded
2024-01-18T21:35:01.661Z,1705613701.661 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-01-18T21:35:01.680Z,1705613701.680 [ElevatorServo] Loaded
2024-01-18T21:35:01.681Z,1705613701.681 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-01-18T21:35:01.699Z,1705613701.699 [MassServo] Loaded
2024-01-18T21:35:01.699Z,1705613701.699 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-01-18T21:35:01.717Z,1705613701.717 [RudderServo] Loaded
2024-01-18T21:35:01.717Z,1705613701.717 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-01-18T21:35:01.732Z,1705613701.732 [ThrusterHE] Loaded
2024-01-18T21:35:01.732Z,1705613701.732 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-01-18T21:35:01.732Z,1705613701.732 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-01-18T21:35:01.733Z,1705613701.733 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-01-18T21:35:01.875Z,1705613701.875 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-01-18T21:35:01.875Z,1705613701.875 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-01-18T21:35:01.888Z,1705613701.888 [NavChart] Loaded
2024-01-18T21:35:01.888Z,1705613701.888 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-01-18T21:35:01.894Z,1705613701.894 [UniversalFixResidualReporter] Loaded
2024-01-18T21:35:01.894Z,1705613701.894 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-01-18T21:35:01.895Z,1705613701.895 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-01-18T21:35:01.895Z,1705613701.895 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-01-18T21:35:01.977Z,1705613701.977 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-01-18T21:35:01.978Z,1705613701.978 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-01-18T21:35:02.774Z,1705613702.774 [AHRS_M2] Loaded
2024-01-18T21:35:02.774Z,1705613702.774 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-01-18T21:35:04.003Z,1705613704.003 [BPC1] Loaded
2024-01-18T21:35:04.004Z,1705613704.004 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-01-18T21:35:04.290Z,1705613704.290 [DataOverHttps] Loaded
2024-01-18T21:35:04.291Z,1705613704.291 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-01-18T21:35:04.292Z,1705613704.292 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0
2024-01-18T21:35:04.292Z,1705613704.292 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6750
2024-01-18T21:35:04.312Z,1705613704.312 [Depth_Keller] Loaded
2024-01-18T21:35:04.312Z,1705613704.312 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-01-18T21:35:04.317Z,1705613704.317 [DropWeight] Loaded
2024-01-18T21:35:04.318Z,1705613704.318 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-01-18T21:35:04.380Z,1705613704.380 [NAL9602] Loaded
2024-01-18T21:35:04.380Z,1705613704.380 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-01-18T21:35:04.410Z,1705613704.410 [Onboard] Loaded
2024-01-18T21:35:04.411Z,1705613704.411 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-01-18T21:35:04.412Z,1705613704.412 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093F4E0
2024-01-18T21:35:04.412Z,1705613704.412 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6751
2024-01-18T21:35:04.425Z,1705613704.425 [Power24vConverter] Loaded
2024-01-18T21:35:04.426Z,1705613704.426 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-01-18T21:35:04.440Z,1705613704.440 [Radio_Surface] Loaded
2024-01-18T21:35:04.440Z,1705613704.440 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-01-18T21:35:04.441Z,1705613704.441 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0
2024-01-18T21:35:04.441Z,1705613704.441 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6752
2024-01-18T21:35:04.455Z,1705613704.455 [Sonardyne_Nano] Loaded
2024-01-18T21:35:04.455Z,1705613704.455 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2024-01-18T21:35:04.456Z,1705613704.456 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-01-18T21:35:04.456Z,1705613704.456 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-01-18T21:35:04.525Z,1705613704.525 [DepthRateCalculator] Loaded
2024-01-18T21:35:04.525Z,1705613704.525 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-01-18T21:35:04.530Z,1705613704.530 [PitchRateCalculator] Loaded
2024-01-18T21:35:04.530Z,1705613704.530 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-01-18T21:35:04.540Z,1705613704.540 [SpeedCalculator] Loaded
2024-01-18T21:35:04.540Z,1705613704.540 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-01-18T21:35:04.544Z,1705613704.544 [YawRateCalculator] Loaded
2024-01-18T21:35:04.544Z,1705613704.544 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-01-18T21:35:04.563Z,1705613704.563 [ElevatorOffsetCalculator] Loaded
2024-01-18T21:35:04.563Z,1705613704.563 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-01-18T21:35:04.563Z,1705613704.563 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-01-18T21:35:04.564Z,1705613704.564 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-01-18T21:35:04.753Z,1705613704.753 [CANONSampler] Loaded
2024-01-18T21:35:04.753Z,1705613704.753 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2024-01-18T21:35:04.813Z,1705613704.813 [CTD_Seabird] Loaded
2024-01-18T21:35:04.814Z,1705613704.814 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-01-18T21:35:04.815Z,1705613704.815 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A2A4E0
2024-01-18T21:35:04.815Z,1705613704.815 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6753
2024-01-18T21:35:04.835Z,1705613704.835 [PAR_Licor] Loaded
2024-01-18T21:35:04.835Z,1705613704.835 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-01-18T21:35:04.876Z,1705613704.876 [WetLabsBB2FL] Loaded
2024-01-18T21:35:04.876Z,1705613704.876 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-01-18T21:35:04.877Z,1705613704.877 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A5A4E0
2024-01-18T21:35:04.877Z,1705613704.877 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6754
2024-01-18T21:35:04.878Z,1705613704.878 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-01-18T21:35:04.879Z,1705613704.879 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-01-18T21:35:04.921Z,1705613704.921 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-01-18T21:35:04.922Z,1705613704.922 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-01-18T21:35:05.312Z,1705613705.312 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-01-18T21:35:05.312Z,1705613705.312 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-01-18T21:35:05.480Z,1705613705.480 [SBIT](DEBUG): Construct Startup Built In Test.
2024-01-18T21:35:05.489Z,1705613705.489 [SBIT] Loaded
2024-01-18T21:35:05.489Z,1705613705.489 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-01-18T21:35:05.492Z,1705613705.492 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-01-18T21:35:05.506Z,1705613705.506 [IBIT] Loaded
2024-01-18T21:35:05.506Z,1705613705.506 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-01-18T21:35:05.512Z,1705613705.512 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-01-18T21:35:05.614Z,1705613705.614 [CBIT] Loaded
2024-01-18T21:35:05.615Z,1705613705.615 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-01-18T21:35:05.615Z,1705613705.615 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-01-18T21:35:05.616Z,1705613705.616 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-01-18T21:35:05.753Z,1705613705.753 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-01-18T21:35:05.759Z,1705613705.759 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-01-18T21:35:05.762Z,1705613705.762 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-01-18T21:35:05.773Z,1705613705.773 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-01-18T21:35:05.774Z,1705613705.774 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BAF4E0
2024-01-18T21:35:05.775Z,1705613705.775 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6755
2024-01-18T21:35:05.779Z,1705613705.779 [Supervisor](INFO): Main Thread ID is 6659
2024-01-18T21:35:05.779Z,1705613705.779 [Supervisor](DEBUG): Running supervisor.
2024-01-18T21:35:05.780Z,1705613705.780 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6756
2024-01-18T21:35:05.780Z,1705613705.780 [CommandExec](INFO): Initializing the command executive.
2024-01-18T21:35:05.782Z,1705613705.782 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6757
2024-01-18T21:35:05.784Z,1705613705.784 [controlThread ThreadHandler](INFO): Handler Thread ID is 6758
2024-01-18T21:35:05.785Z,1705613705.785 [controlThread](DEBUG): Initializing ControlThread
2024-01-18T21:35:05.786Z,1705613705.786 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-01-18T21:35:05.787Z,1705613705.787 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-01-18T21:35:05.788Z,1705613705.788 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-01-18T21:35:05.789Z,1705613705.789 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-01-18T21:35:05.791Z,1705613705.791 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-01-18T21:35:05.791Z,1705613705.791 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-01-18T21:35:05.795Z,1705613705.795 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-01-18T21:35:05.795Z,1705613705.795 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-01-18T21:35:05.796Z,1705613705.796 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-01-18T21:35:05.796Z,1705613705.796 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-01-18T21:35:05.797Z,1705613705.797 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-01-18T21:35:05.801Z,1705613705.801 [SBIT](INFO): Initialize SBIT Component.
2024-01-18T21:35:05.802Z,1705613705.802 [SBIT](IMPORTANT): git: 2023-12-07
2024-01-18T21:35:05.802Z,1705613705.802 [SBIT](INFO): git hash: dbc7300d59e166afd06c26988583bb6e3d4bec93
2024-01-18T21:35:05.802Z,1705613705.802 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-01-18T21:35:05.803Z,1705613705.803 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2024-01-18T21:35:05.804Z,1705613705.804 [SBIT](INFO): Beginning SBIT in 86.000000 seconds.
2024-01-18T21:35:05.805Z,1705613705.805 [IBIT](INFO): Initialize IBIT Component.
2024-01-18T21:35:05.806Z,1705613705.806 [CBIT](DEBUG): Initialize CBIT Component.
2024-01-18T21:35:05.807Z,1705613705.807 [logger ThreadHandler](INFO): Handler Thread ID is 6759
2024-01-18T21:35:05.817Z,1705613705.817 [CBIT](DEBUG): Initialized mux pins.
2024-01-18T21:35:05.817Z,1705613705.817 [CBIT](DEBUG): Initializing the watchdog timer.
2024-01-18T21:35:05.825Z,1705613705.825 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6760
2024-01-18T21:35:05.827Z,1705613705.827 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-01-18T21:35:05.837Z,1705613705.837 [Onboard ThreadHandler](INFO): Handler Thread ID is 6761
2024-01-18T21:35:05.842Z,1705613705.842 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-01-18T21:35:05.842Z,1705613705.842 [CBIT](DEBUG): Initializing heartbeat.
2024-01-18T21:35:05.860Z,1705613705.860 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6762
2024-01-18T21:35:05.877Z,1705613705.877 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6763
2024-01-18T21:35:05.877Z,1705613705.877 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-01-18T21:35:05.879Z,1705613705.879 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6765
2024-01-18T21:35:05.887Z,1705613705.887 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6767
2024-01-18T21:35:05.890Z,1705613705.890 [WetLabsBB2FL](INFO): Powering up
2024-01-18T21:35:05.894Z,1705613705.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-01-18T21:35:05.895Z,1705613705.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-01-18T21:35:05.896Z,1705613705.896 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-01-18T21:35:05.913Z,1705613705.913 [CBIT](DEBUG): Deactivating GF circuits.
2024-01-18T21:35:05.913Z,1705613705.913 [CBIT](DEBUG): Deactivating emergency mode.
2024-01-18T21:35:05.953Z,1705613705.953 [CBIT](DEBUG): Backplane powered.
2024-01-18T21:35:05.954Z,1705613705.954 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2024-01-18T21:35:05.999Z,1705613705.999 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-01-18T21:35:06.022Z,1705613706.022 [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>


2024-01-18T21:35:06.023Z,1705613706.023 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2024-01-18T21:35:06.122Z,1705613706.122 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-01-18T21:35:06.123Z,1705613706.123 [Default:A.Wait](DEBUG): Construct Wait.
2024-01-18T21:35:06.134Z,1705613706.134 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-01-18T21:35:06.161Z,1705613706.161 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-01-18T21:35:06.163Z,1705613706.163 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-01-18T21:35:06.202Z,1705613706.202 [Default:E.Execute](DEBUG): Construct Execute.
2024-01-18T21:35:06.229Z,1705613706.229 [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>


2024-01-18T21:35:06.234Z,1705613706.234 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2024-01-18T21:35:06.269Z,1705613706.269 [Radio_Surface](INFO): Powering up
2024-01-18T21:35:06.270Z,1705613706.270 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-01-18T21:35:06.342Z,1705613706.342 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1831.023193 decibar, 0.000000 m
2024-01-18T21:35:06.343Z,1705613706.343 [Power24vConverter](INFO): Powering up.
2024-01-18T21:35:06.344Z,1705613706.344 [Sonardyne_Nano](INFO): Initializing.
2024-01-18T21:35:06.369Z,1705613706.369 [CANONSampler](INFO): Powering down
2024-01-18T21:35:06.386Z,1705613706.386 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-01-18T21:35:06.464Z,1705613706.464 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-01-18T21:35:06.469Z,1705613706.469 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-01-18T21:35:06.470Z,1705613706.470 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-01-18T21:35:06.477Z,1705613706.477 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-01-18T21:35:06.478Z,1705613706.478 [MassServo](DEBUG): Initializing EZServoServo.
2024-01-18T21:35:06.485Z,1705613706.485 [MassServo](DEBUG): Initializing MassServo.
2024-01-18T21:35:06.486Z,1705613706.486 [RudderServo](DEBUG): Initializing EZServoServo.
2024-01-18T21:35:06.493Z,1705613706.493 [RudderServo](DEBUG): Initializing RudderServo.
2024-01-18T21:35:06.494Z,1705613706.494 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-01-18T21:35:06.501Z,1705613706.501 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-01-18T21:35:08.493Z,1705613708.493 [WetLabsBB2FL](INFO): Powering down
2024-01-18T21:35:08.668Z,1705613708.668 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2024-01-18T21:35:09.906Z,1705613709.906 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109
2024-01-18T21:35:12.150Z,1705613712.150 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-01-18T21:35:12.910Z,1705613712.910 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2024-01-18T21:35:19.719Z,1705613719.719 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004721
2024-01-18T21:35:34.527Z,1705613734.527 [NAL9602](INFO): Powering up NAL9602
2024-01-18T21:35:45.447Z,1705613745.447 [NAL9602](INFO): NAL9602 initialized
2024-01-18T21:36:04.178Z,1705613764.178 [CommandExec](IMPORTANT): got command strobe off
2024-01-18T21:36:04.178Z,1705613764.178 [CommandExec](IMPORTANT): Deactivating strobe
2024-01-18T21:36:32.317Z,1705613792.317 [SBIT](IMPORTANT): Beginning Startup BIT
2024-01-18T21:36:32.321Z,1705613792.321 [CBIT](IMPORTANT): Beginning ground fault scan
2024-01-18T21:36:43.256Z,1705613803.256 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-01-18T21:36:43.652Z,1705613803.652 [CBIT](IMPORTANT): Beginning ground fault scan
2024-01-18T21:36:54.718Z,1705613814.718 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-01-18T21:36:55.012Z,1705613815.012 [CBIT](IMPORTANT): Beginning ground fault scan
2024-01-18T21:37:05.863Z,1705613825.863 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.014156
CHAN A1 (24V): 0.000298
CHAN A2 (12V): -0.002121
CHAN A3 (5V): -0.001271
CHAN B0 (3.3V): -0.000255
CHAN B1 (3.15aV): -0.000505
CHAN B2 (3.15bV): -0.000029
CHAN B3 (GND): -0.000132
OPEN: -0.000582
Full Scale: +/- 1 mA
2024-01-18T21:37:26.465Z,1705613846.465 [SBIT](IMPORTANT): SBIT PASSED
2024-01-18T21:37:26.465Z,1705613846.465 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-01-18T21:37:26.466Z,1705613846.466 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2024-01-18T21:37:26.466Z,1705613846.466 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2024-01-18T21:37:26.466Z,1705613846.466 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2024-01-18T21:37:26.466Z,1705613846.466 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2024-01-18T21:37:26.467Z,1705613846.467 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2024-01-18T21:37:26.467Z,1705613846.467 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2024-01-18T21:37:26.467Z,1705613846.467 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent;

2024-01-18T21:37:26.467Z,1705613846.467 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=384.168365 cubic_centimeter;

2024-01-18T21:37:26.467Z,1705613846.467 [SBIT](IMPORTANT): VerticalControl.massDefault=-16.615593 millimeter;

2024-01-18T21:37:26.855Z,1705613846.855 [MissionManager](IMPORTANT): Started mission Startup
2024-01-18T21:37:26.855Z,1705613846.855 [Startup] Running Loop=1
2024-01-18T21:37:26.856Z,1705613846.856 [Startup](DEBUG): Aggregate::initialize Startup
2024-01-18T21:37:26.856Z,1705613846.856 [Startup:A.GoToSurface] Running Loop=1
2024-01-18T21:37:26.856Z,1705613846.856 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-01-18T21:37:26.856Z,1705613846.856 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-01-18T21:37:26.857Z,1705613846.857 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-01-18T21:37:26.857Z,1705613846.857 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-01-18T21:37:26.858Z,1705613846.858 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-01-18T21:37:26.858Z,1705613846.858 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-01-18T21:37:26.860Z,1705613846.860 [Startup:StartupSatComms] Running Loop=1
2024-01-18T21:37:26.860Z,1705613846.860 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-01-18T21:37:26.860Z,1705613846.860 [Startup:StartupSatComms:A] Running Loop=1
2024-01-18T21:37:27.260Z,1705613847.260 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-01-18T21:37:41.725Z,1705613861.725 [CommandExec](IMPORTANT): got command failComponent
2024-01-18T21:37:41.726Z,1705613861.726 [CommandExec](IMPORTANT): Failed components:
2024-01-18T21:37:41.726Z,1705613861.726 [CommandExec](IMPORTANT): No failed Components.
2024-01-18T21:38:06.045Z,1705613886.045 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-01-18T21:38:06.045Z,1705613886.045 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:38:06.056Z,1705613886.056 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:38:06.468Z,1705613886.468 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:38:06.468Z,1705613886.468 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-01-18T21:38:18.323Z,1705613898.323 [CommandExec](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch
2024-01-18T21:38:18.324Z,1705613898.324 [CommandExec](IMPORTANT): Onboard.Pressure 9.716044 psi
2024-01-18T21:38:27.047Z,1705613907.047 [Startup:StartupSatComms:A](INFO): Timed out from 2024-01-18T21:37:26.9Z
2024-01-18T21:38:27.047Z,1705613907.047 [Startup:StartupSatComms:A] Stopped
2024-01-18T21:38:27.047Z,1705613907.047 [Startup:StartupSatComms:B] Running Loop=1
2024-01-18T21:38:27.536Z,1705613907.536 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-01-18T21:38:27.931Z,1705613907.931 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2024-01-18T21:38:29.279Z,1705613909.279 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2024-01-18T21:38:29.280Z,1705613909.280 [CommandExec](IMPORTANT): Onboard.Humidity 13.075326 %
2024-01-18T21:38:35.066Z,1705613915.066 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20231218T222257/Courier0004.lzma
2024-01-18T21:38:36.067Z,1705613916.067 [DataOverHttps](INFO): Moved sent file to Logs/20231218T222257/Courier0004.lzma.bak
2024-01-18T21:38:36.067Z,1705613916.067 [DataOverHttps](INFO): SBD MOMSN=19164225
2024-01-18T21:38:51.748Z,1705613931.748 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20240118T213454/Courier0000.lzma
2024-01-18T21:38:52.751Z,1705613932.751 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0000.lzma.bak
2024-01-18T21:38:52.751Z,1705613932.751 [DataOverHttps](INFO): SBD MOMSN=19164227
2024-01-18T21:39:08.390Z,1705613948.390 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20231218T222257/Express0005.lzma
2024-01-18T21:39:09.391Z,1705613949.391 [DataOverHttps](INFO): Moved sent file to Logs/20231218T222257/Express0005.lzma.bak
2024-01-18T21:39:09.391Z,1705613949.391 [DataOverHttps](INFO): SBD MOMSN=19164230
2024-01-18T21:39:24.902Z,1705613964.902 [DataOverHttps](INFO): Sending 988 bytes from file Logs/20240118T213454/Express0001.lzma
2024-01-18T21:39:25.895Z,1705613965.895 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0001.lzma.bak
2024-01-18T21:39:25.895Z,1705613965.895 [DataOverHttps](INFO): SBD MOMSN=19164239
2024-01-18T21:39:27.271Z,1705613967.271 [Startup:StartupSatComms:B](INFO): Timed out from 2024-01-18T21:38:27.0Z
2024-01-18T21:39:27.271Z,1705613967.271 [Startup:StartupSatComms:B] Stopped
2024-01-18T21:39:27.272Z,1705613967.272 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-01-18T21:39:27.272Z,1705613967.272 [Startup:StartupSatComms] Stopped
2024-01-18T21:39:27.272Z,1705613967.272 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-01-18T21:39:27.273Z,1705613967.273 [Startup](INFO): Completed Startup
2024-01-18T21:39:27.273Z,1705613967.273 [MissionManager](INFO): Startup is completed.
2024-01-18T21:39:27.273Z,1705613967.273 [MissionManager](INFO): Uninitializing Mission Startup
2024-01-18T21:39:27.273Z,1705613967.273 [Startup] Stopped
2024-01-18T21:39:27.273Z,1705613967.273 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-01-18T21:39:27.273Z,1705613967.273 [Startup:A.GoToSurface] Stopped
2024-01-18T21:39:27.273Z,1705613967.273 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-01-18T21:39:27.691Z,1705613967.691 [MissionManager](IMPORTANT): Started mission Default
2024-01-18T21:39:27.691Z,1705613967.691 [Default] Running Loop=1
2024-01-18T21:39:27.691Z,1705613967.691 [Default](DEBUG): Aggregate::initialize Default
2024-01-18T21:39:27.691Z,1705613967.691 [Default:B.GoToSurface] Running Loop=1
2024-01-18T21:39:27.691Z,1705613967.691 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-01-18T21:39:27.691Z,1705613967.691 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-01-18T21:39:27.692Z,1705613967.692 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-01-18T21:39:27.692Z,1705613967.692 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-01-18T21:39:27.692Z,1705613967.692 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-01-18T21:39:27.693Z,1705613967.693 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-01-18T21:39:27.693Z,1705613967.693 [Default:A.Wait] Running Loop=1
2024-01-18T21:39:27.693Z,1705613967.693 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-01-18T21:39:40.997Z,1705613980.997 [Default:A.Wait](INFO): Done Waiting.
2024-01-18T21:39:40.997Z,1705613980.997 [Default:A.Wait] Stopped
2024-01-18T21:39:40.997Z,1705613980.997 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T21:39:41.409Z,1705613981.409 [Default:CheckIn] Running Loop=1
2024-01-18T21:39:41.410Z,1705613981.410 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T21:39:41.410Z,1705613981.410 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T21:39:41.824Z,1705613981.824 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-01-18T21:40:48.869Z,1705614048.869 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T21:41:07.058Z,1705614067.058 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2024-01-18T21:41:07.058Z,1705614067.058 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:41:07.069Z,1705614067.069 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:41:07.546Z,1705614067.546 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:41:07.546Z,1705614067.546 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2024-01-18T21:41:42.610Z,1705614102.610 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5.
2024-01-18T21:41:42.617Z,1705614102.617 [BPC1](INFO): Received data from all battery sticks.
2024-01-18T21:44:08.102Z,1705614248.102 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2024-01-18T21:44:08.102Z,1705614248.102 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:44:08.113Z,1705614248.113 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:44:08.517Z,1705614248.517 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:44:08.517Z,1705614248.517 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2024-01-18T21:44:41.601Z,1705614281.601 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-01-18T21:39:41.4Z
2024-01-18T21:44:41.601Z,1705614281.601 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T21:44:41.601Z,1705614281.601 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T21:44:42.007Z,1705614282.007 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-01-18T21:44:48.616Z,1705614288.616 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20240118T213454/Courier0004.lzma
2024-01-18T21:44:49.619Z,1705614289.619 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0004.lzma.bak
2024-01-18T21:44:49.619Z,1705614289.619 [DataOverHttps](INFO): SBD MOMSN=19164269
2024-01-18T21:45:07.480Z,1705614307.480 [Power24vConverter](INFO): Powering down.
2024-01-18T21:45:07.793Z,1705614307.793 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20240118T213454/Express0005.lzma
2024-01-18T21:45:08.795Z,1705614308.795 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0005.lzma.bak
2024-01-18T21:45:08.795Z,1705614308.795 [DataOverHttps](INFO): SBD MOMSN=19164271
2024-01-18T21:45:10.316Z,1705614310.316 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T21:45:10.316Z,1705614310.316 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T21:45:10.316Z,1705614310.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T21:45:48.283Z,1705614348.283 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-01-18T21:45:48.283Z,1705614348.283 [NAL9602] Data Fault, FailCount= 1
2024-01-18T21:45:48.283Z,1705614348.283 [NAL9602](ERROR): Data Fault
2024-01-18T21:45:48.300Z,1705614348.300 [CBIT](ERROR): Data Fault in component: NAL9602
2024-01-18T21:45:48.686Z,1705614348.686 [NAL9602](INFO): Powering down
2024-01-18T21:45:49.511Z,1705614349.511 [CBIT](INFO): Clearing failed state for component NAL9602
2024-01-18T21:45:49.511Z,1705614349.511 [NAL9602] No Fault, FailCount= 1
2024-01-18T21:46:18.986Z,1705614378.986 [NAL9602](INFO): Powering up NAL9602
2024-01-18T21:46:29.894Z,1705614389.894 [NAL9602](INFO): NAL9602 initialized
2024-01-18T21:47:09.089Z,1705614429.089 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2024-01-18T21:47:09.089Z,1705614429.089 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:47:09.100Z,1705614429.100 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:47:09.508Z,1705614429.508 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:47:09.508Z,1705614429.508 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2024-01-18T21:50:10.081Z,1705614610.081 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2024-01-18T21:50:10.081Z,1705614610.081 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:50:10.092Z,1705614610.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:50:10.500Z,1705614610.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:50:10.501Z,1705614610.501 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2024-01-18T21:50:10.890Z,1705614610.890 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T21:50:10.890Z,1705614610.890 [Default:CheckIn:C.Wait] Stopped
2024-01-18T21:50:10.891Z,1705614610.891 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T21:50:10.891Z,1705614610.891 [Default:CheckIn:D] Running Loop=1
2024-01-18T21:50:11.295Z,1705614611.295 [Default:CheckIn:D] Stopped
2024-01-18T21:50:11.295Z,1705614611.295 [Default:CheckIn:E] Running Loop=1
2024-01-18T21:50:11.719Z,1705614611.719 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.726726 min 
2024-01-18T21:50:11.719Z,1705614611.719 [Default:CheckIn:E] Stopped
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn] Stopped
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn](INFO): Running loop #2
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn] Running Loop=2
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T21:50:11.720Z,1705614611.720 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T21:53:11.143Z,1705614791.143 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2024-01-18T21:53:11.143Z,1705614791.143 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:53:11.154Z,1705614791.154 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:53:11.575Z,1705614791.575 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:53:11.575Z,1705614791.575 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2024-01-18T21:55:12.119Z,1705614912.119 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-01-18T21:50:11.7Z
2024-01-18T21:55:12.119Z,1705614912.119 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T21:55:12.119Z,1705614912.119 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T21:55:18.852Z,1705614918.852 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240118T213454/Courier0007.lzma
2024-01-18T21:55:19.855Z,1705614919.855 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0007.lzma.bak
2024-01-18T21:55:19.855Z,1705614919.855 [DataOverHttps](INFO): SBD MOMSN=19164277
2024-01-18T21:55:35.840Z,1705614935.840 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20240118T213454/Express0008.lzma
2024-01-18T21:55:36.843Z,1705614936.843 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0008.lzma.bak
2024-01-18T21:55:36.843Z,1705614936.843 [DataOverHttps](INFO): SBD MOMSN=19164279
2024-01-18T21:55:38.379Z,1705614938.379 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T21:55:38.379Z,1705614938.379 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T21:55:38.379Z,1705614938.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T21:56:12.342Z,1705614972.342 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2024-01-18T21:56:12.342Z,1705614972.342 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:56:12.359Z,1705614972.359 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:56:12.765Z,1705614972.765 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:56:12.765Z,1705614972.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2024-01-18T21:56:30.882Z,1705614990.882 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-01-18T21:56:30.882Z,1705614990.882 [NAL9602] Data Fault, FailCount= 2
2024-01-18T21:56:30.883Z,1705614990.883 [NAL9602](ERROR): Data Fault
2024-01-18T21:56:30.900Z,1705614990.900 [CBIT](ERROR): Data Fault in component: NAL9602
2024-01-18T21:56:31.282Z,1705614991.282 [NAL9602](INFO): Powering down
2024-01-18T21:56:32.124Z,1705614992.124 [CBIT](INFO): Clearing failed state for component NAL9602
2024-01-18T21:56:32.124Z,1705614992.124 [NAL9602] No Fault, FailCount= 2
2024-01-18T21:57:01.583Z,1705615021.583 [NAL9602](INFO): Powering up NAL9602
2024-01-18T21:57:12.490Z,1705615032.490 [NAL9602](INFO): NAL9602 initialized
2024-01-18T21:59:13.298Z,1705615153.298 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2024-01-18T21:59:13.298Z,1705615153.298 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T21:59:13.345Z,1705615153.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T21:59:13.755Z,1705615153.755 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T21:59:13.755Z,1705615153.755 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2024-01-18T22:00:38.946Z,1705615238.946 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T22:00:38.946Z,1705615238.946 [Default:CheckIn:C.Wait] Stopped
2024-01-18T22:00:38.946Z,1705615238.946 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:00:38.946Z,1705615238.946 [Default:CheckIn:D] Running Loop=1
2024-01-18T22:00:39.351Z,1705615239.351 [Default:CheckIn:D] Stopped
2024-01-18T22:00:39.351Z,1705615239.351 [Default:CheckIn:E] Running Loop=1
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.194338 min 
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn:E] Stopped
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn] Stopped
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn](INFO): Running loop #3
2024-01-18T22:00:39.764Z,1705615239.764 [Default:CheckIn] Running Loop=3
2024-01-18T22:00:39.765Z,1705615239.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T22:00:39.765Z,1705615239.765 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T22:02:14.304Z,1705615334.304 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2024-01-18T22:02:14.304Z,1705615334.304 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-01-18T22:02:14.315Z,1705615334.315 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-01-18T22:02:14.723Z,1705615334.723 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-01-18T22:02:14.723Z,1705615334.723 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2024-01-18T22:02:37.732Z,1705615357.732 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220236.00,A,3648.16212,N,12147.27638,W,0.039,0.00,180124,,,A*79
2024-01-18T22:02:37.765Z,1705615357.765 [NAL9602](INFO): GPS fix at 20240118T220236: (36.802702, -121.787940)
2024-01-18T22:02:37.776Z,1705615357.776 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T22:02:37.776Z,1705615357.776 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T22:02:46.992Z,1705615366.992 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20240118T213454/Courier0010.lzma
2024-01-18T22:02:47.995Z,1705615367.995 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0010.lzma.bak
2024-01-18T22:02:47.995Z,1705615367.995 [DataOverHttps](INFO): SBD MOMSN=19164297
2024-01-18T22:03:09.225Z,1705615389.225 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20240118T213454/Express0011.lzma
2024-01-18T22:03:10.227Z,1705615390.227 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0011.lzma.bak
2024-01-18T22:03:10.227Z,1705615390.227 [DataOverHttps](INFO): SBD MOMSN=19164304
2024-01-18T22:03:10.530Z,1705615390.530 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T22:03:11.757Z,1705615391.757 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T22:03:11.757Z,1705615391.757 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T22:03:11.757Z,1705615391.757 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:04:20.982Z,1705615460.982 [DataOverHttps](IMPORTANT): SBD MTMSN=20240118T220420
2024-01-18T22:04:30.321Z,1705615470.321 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.tl
2024-01-18T22:04:30.376Z,1705615470.376 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.tl
2024-01-18T22:04:30.376Z,1705615470.376 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.tl
2024-01-18T22:04:30.376Z,1705615470.376 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Maintenance/tank_ballast_and_trim.tx
2024-01-18T22:04:30.449Z,1705615470.449 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2024-01-18T22:04:30.452Z,1705615470.452 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2024-01-18T22:04:30.455Z,1705615470.455 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2024-01-18T22:04:30.458Z,1705615470.458 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2024-01-18T22:04:30.460Z,1705615470.460 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2024-01-18T22:04:30.463Z,1705615470.463 [MissionManager](INFO): DefineArg ballast_and_trim.TargetDepthTimeout = 20.000000 min
2024-01-18T22:04:30.466Z,1705615470.466 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2024-01-18T22:04:30.469Z,1705615470.469 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2024-01-18T22:04:30.471Z,1705615470.471 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2024-01-18T22:04:30.474Z,1705615470.474 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2024-01-18T22:04:30.477Z,1705615470.477 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2024-01-18T22:04:30.480Z,1705615470.480 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2024-01-18T22:04:30.519Z,1705615470.519 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2024-01-18T22:04:30.519Z,1705615470.519 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.tl
2024-01-18T22:04:30.519Z,1705615470.519 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/Science.tx
2024-01-18T22:04:30.925Z,1705615470.925 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2024-01-18T22:04:30.928Z,1705615470.928 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2024-01-18T22:04:30.930Z,1705615470.930 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2024-01-18T22:04:30.933Z,1705615470.933 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2024-01-18T22:04:30.935Z,1705615470.935 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2024-01-18T22:04:30.982Z,1705615470.982 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2024-01-18T22:04:30.984Z,1705615470.984 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2024-01-18T22:04:30.996Z,1705615470.996 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2024-01-18T22:04:31.003Z,1705615471.003 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2024-01-18T22:04:31.018Z,1705615471.018 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2024-01-18T22:04:31.020Z,1705615471.020 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2024-01-18T22:04:31.027Z,1705615471.027 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2024-01-18T22:04:31.034Z,1705615471.034 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2024-01-18T22:04:31.036Z,1705615471.036 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2024-01-18T22:04:31.047Z,1705615471.047 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2024-01-18T22:04:31.050Z,1705615471.050 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2024-01-18T22:04:31.058Z,1705615471.058 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2024-01-18T22:04:31.062Z,1705615471.062 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2024-01-18T22:04:31.079Z,1705615471.079 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2024-01-18T22:04:31.083Z,1705615471.083 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2024-01-18T22:04:31.088Z,1705615471.088 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2024-01-18T22:04:31.099Z,1705615471.099 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2024-01-18T22:04:31.103Z,1705615471.103 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2024-01-18T22:04:31.114Z,1705615471.114 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2024-01-18T22:04:31.121Z,1705615471.121 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2024-01-18T22:04:31.124Z,1705615471.124 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2024-01-18T22:04:31.131Z,1705615471.131 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlThreshTriggerActive = 0 bool
2024-01-18T22:04:31.146Z,1705615471.146 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlLowerThresh = nan ug/l
2024-01-18T22:04:31.153Z,1705615471.153 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlUpperThresh = nan ug/l
2024-01-18T22:04:31.156Z,1705615471.156 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesThresh = 5.000000 count
2024-01-18T22:04:31.159Z,1705615471.159 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = nan ug/l
2024-01-18T22:04:31.171Z,1705615471.171 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = nan m
2024-01-18T22:04:31.175Z,1705615471.175 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = nan degC
2024-01-18T22:04:31.190Z,1705615471.190 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2024-01-18T22:04:31.194Z,1705615471.194 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2024-01-18T22:04:31.205Z,1705615471.205 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = nan umol/l
2024-01-18T22:04:31.208Z,1705615471.208 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = nan m
2024-01-18T22:04:31.215Z,1705615471.215 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2024-01-18T22:04:31.229Z,1705615471.229 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2024-01-18T22:04:31.237Z,1705615471.237 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = nan kg/m3
2024-01-18T22:04:31.240Z,1705615471.240 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = nan m
2024-01-18T22:04:31.247Z,1705615471.247 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2024-01-18T22:04:31.261Z,1705615471.261 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2024-01-18T22:04:31.264Z,1705615471.264 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = nan ppb
2024-01-18T22:04:31.271Z,1705615471.271 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = nan m
2024-01-18T22:04:31.275Z,1705615471.275 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2024-01-18T22:04:31.286Z,1705615471.286 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2024-01-18T22:04:31.293Z,1705615471.293 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2024-01-18T22:04:31.296Z,1705615471.296 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2024-01-18T22:04:31.306Z,1705615471.306 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = nan psu
2024-01-18T22:04:31.309Z,1705615471.309 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = nan m
2024-01-18T22:04:31.312Z,1705615471.312 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = nan degC
2024-01-18T22:04:31.319Z,1705615471.319 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2024-01-18T22:04:31.338Z,1705615471.338 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2024-01-18T22:04:31.341Z,1705615471.341 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = nan ug/l
2024-01-18T22:04:31.344Z,1705615471.344 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = nan m
2024-01-18T22:04:31.387Z,1705615471.387 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2024-01-18T22:04:31.396Z,1705615471.396 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2024-01-18T22:04:31.416Z,1705615471.416 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2024-01-18T22:04:31.429Z,1705615471.429 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = nan psu
2024-01-18T22:04:31.432Z,1705615471.432 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = nan m
2024-01-18T22:04:31.443Z,1705615471.443 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2024-01-18T22:04:31.446Z,1705615471.446 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2024-01-18T22:04:31.450Z,1705615471.450 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2024-01-18T22:04:31.461Z,1705615471.461 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = nan psu
2024-01-18T22:04:31.473Z,1705615471.473 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = nan m
2024-01-18T22:04:31.479Z,1705615471.479 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2024-01-18T22:04:31.482Z,1705615471.482 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2024-01-18T22:04:31.486Z,1705615471.486 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2024-01-18T22:04:31.498Z,1705615471.498 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.TriggeredOnChl = 0 bool
2024-01-18T22:04:31.501Z,1705615471.501 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.ChlTriggering = nan ug/l
2024-01-18T22:04:31.577Z,1705615471.577 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2024-01-18T22:04:31.602Z,1705615471.602 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2024-01-18T22:04:31.627Z,1705615471.627 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2024-01-18T22:04:31.670Z,1705615471.670 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2024-01-18T22:04:31.680Z,1705615471.680 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2024-01-18T22:04:31.721Z,1705615471.721 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2024-01-18T22:04:31.779Z,1705615471.779 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2024-01-18T22:04:31.820Z,1705615471.820 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2024-01-18T22:04:31.851Z,1705615471.851 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Construct ValueDetect.
2024-01-18T22:04:31.871Z,1705615471.871 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2024-01-18T22:04:31.872Z,1705615471.872 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BackseatDriver.tx
2024-01-18T22:04:31.904Z,1705615471.904 [MissionManager](INFO): DefineArg ballast_and_trim:BackseatDriver.EnableBackseat = 0 bool
2024-01-18T22:04:32.384Z,1705615472.384 [ballast_and_trim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2024-01-18T22:04:32.405Z,1705615472.405 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.tl
2024-01-18T22:04:32.406Z,1705615472.406 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BallastAndTrim.tx
2024-01-18T22:04:32.656Z,1705615472.656 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2024-01-18T22:04:32.668Z,1705615472.668 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2024-01-18T22:04:32.680Z,1705615472.680 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2024-01-18T22:04:32.687Z,1705615472.687 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2024-01-18T22:04:32.695Z,1705615472.695 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2024-01-18T22:04:32.709Z,1705615472.709 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2024-01-18T22:04:32.712Z,1705615472.712 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2024-01-18T22:04:32.720Z,1705615472.720 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2024-01-18T22:04:32.723Z,1705615472.723 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2024-01-18T22:04:32.734Z,1705615472.734 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2024-01-18T22:04:32.741Z,1705615472.741 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2024-01-18T22:04:32.744Z,1705615472.744 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2024-01-18T22:04:32.751Z,1705615472.751 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2024-01-18T22:04:32.755Z,1705615472.755 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2024-01-18T22:04:32.793Z,1705615472.793 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2024-01-18T22:04:32.800Z,1705615472.800 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2024-01-18T22:04:32.804Z,1705615472.804 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2024-01-18T22:04:32.820Z,1705615472.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2024-01-18T22:04:32.824Z,1705615472.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2024-01-18T22:04:32.839Z,1705615472.839 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2024-01-18T22:04:32.849Z,1705615472.849 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-01-18T22:04:32.852Z,1705615472.852 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2024-01-18T22:04:32.875Z,1705615472.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2024-01-18T22:04:32.882Z,1705615472.882 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2024-01-18T22:04:32.884Z,1705615472.884 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute](DEBUG): Construct Execute.
2024-01-18T22:04:32.898Z,1705615472.898 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](DEBUG): Construct BallastAndTrim.
2024-01-18T22:04:32.936Z,1705615472.936 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2024-01-18T22:04:32.937Z,1705615472.937 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.TargetDepthTimeout
2024-01-18T22:04:32.939Z,1705615472.939 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2024-01-18T22:04:32.941Z,1705615472.941 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2024-01-18T22:04:32.942Z,1705615472.942 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2024-01-18T22:04:32.944Z,1705615472.944 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2024-01-18T22:04:32.946Z,1705615472.946 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2024-01-18T22:04:32.948Z,1705615472.948 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2024-01-18T22:04:33.006Z,1705615473.006 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2024-01-18T22:04:33.010Z,1705615473.010 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2024-01-18T22:04:33.085Z,1705615473.085 [MissionManager](DEBUG): 
mission ballast_and_trim {
  arguments {
    MissionTimeout = 120 minute
      """
      Maximum duration of mission.
      """

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

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

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

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

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

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

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

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

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

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

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

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

  timeout duration=MissionTimeout

  insert Insert/Science.tl

  insert Insert/BackseatDriver.tl

  aggregate RunBallastAndTrim {
    run in sequence

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

    aggregate Depth1 {
      run in sequence

      break if ( isNaN ( Depth1 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth1

      call refId="BallastAndTrim"
    }

    aggregate Depth2 {
      run in sequence

      break if ( isNaN ( Depth2 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth2

      call refId="BallastAndTrim"
    }
  }

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

    run in sequence

    break if ( Universal:depth < SurfaceThreshold )

    behavior Guidance:Buoyancy {
      run in parallel

      set position = Control:VerticalControl.buoyancyDefault
    }

    behavior Guidance:Wait {
      run in sequence

      set duration = WaitToFloat
    }
  }
}


2024-01-18T22:04:33.089Z,1705615473.089 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.tl
2024-01-18T22:04:33.404Z,1705615473.404 [Default] Stopped
2024-01-18T22:04:33.404Z,1705615473.404 [Default](DEBUG): Aggregate::uninitialize Default
2024-01-18T22:04:33.404Z,1705615473.404 [Default:B.GoToSurface] Stopped
2024-01-18T22:04:33.409Z,1705615473.409 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-01-18T22:04:33.409Z,1705615473.409 [Default:CheckIn] Stopped
2024-01-18T22:04:33.409Z,1705615473.409 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T22:04:33.409Z,1705615473.409 [Default:CheckIn:C.Wait] Stopped
2024-01-18T22:04:33.410Z,1705615473.410 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:04:33.410Z,1705615473.410 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim] Running Loop=1
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim:Science] Running Loop=1
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim:Science:A] Running Loop=1
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim:Science:B] Running Loop=1
2024-01-18T22:04:33.410Z,1705615473.410 [ballast_and_trim:Science:C] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:D] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:E] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:F] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2024-01-18T22:04:33.411Z,1705615473.411 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2024-01-18T22:04:33.418Z,1705615473.418 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2024-01-18T22:04:33.418Z,1705615473.418 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2024-01-18T22:04:33.418Z,1705615473.418 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2024-01-18T22:04:33.419Z,1705615473.419 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2024-01-18T22:04:33.419Z,1705615473.419 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2024-01-18T22:04:33.419Z,1705615473.419 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2024-01-18T22:04:33.419Z,1705615473.419 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2024-01-18T22:04:33.419Z,1705615473.419 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2024-01-18T22:04:33.423Z,1705615473.423 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2024-01-18T22:04:33.423Z,1705615473.423 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2024-01-18T22:04:33.423Z,1705615473.423 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2024-01-18T22:04:33.423Z,1705615473.423 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2024-01-18T22:04:33.433Z,1705615473.433 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2024-01-18T22:04:33.433Z,1705615473.433 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2024-01-18T22:04:33.433Z,1705615473.433 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2024-01-18T22:04:33.433Z,1705615473.433 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2024-01-18T22:04:33.434Z,1705615473.434 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2024-01-18T22:04:33.434Z,1705615473.434 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2024-01-18T22:04:33.434Z,1705615473.434 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2024-01-18T22:04:33.434Z,1705615473.434 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2024-01-18T22:04:33.436Z,1705615473.436 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2024-01-18T22:04:33.436Z,1705615473.436 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2024-01-18T22:04:33.436Z,1705615473.436 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2024-01-18T22:04:33.436Z,1705615473.436 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2024-01-18T22:04:33.442Z,1705615473.442 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2024-01-18T22:04:33.442Z,1705615473.442 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2024-01-18T22:04:33.442Z,1705615473.442 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2024-01-18T22:04:33.442Z,1705615473.442 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2024-01-18T22:04:33.443Z,1705615473.443 [ballast_and_trim:Science:ChlThreshTrigger] Running Loop=1
2024-01-18T22:04:33.443Z,1705615473.443 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::initialize ballast_and_trim:Science:ChlThreshTrigger
2024-01-18T22:04:33.443Z,1705615473.443 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Running Loop=1
2024-01-18T22:04:33.443Z,1705615473.443 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](INFO): Initialize.
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:BackseatDriver] Running Loop=1
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::initialize ballast_and_trim:BackseatDriver
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Running Loop=1
2024-01-18T22:04:33.444Z,1705615473.444 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2024-01-18T22:04:33.449Z,1705615473.449 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2024-01-18T22:04:33.449Z,1705615473.449 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2024-01-18T22:04:33.449Z,1705615473.449 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2024-01-18T22:04:33.449Z,1705615473.449 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2024-01-18T22:04:33.450Z,1705615473.450 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2024-01-18T22:04:33.450Z,1705615473.450 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2024-01-18T22:04:33.450Z,1705615473.450 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2024-01-18T22:04:33.450Z,1705615473.450 [ballast_and_trim:BackseatDriver] Running Loop=1
2024-01-18T22:04:33.451Z,1705615473.451 [ballast_and_trim:Science] Running Loop=1
2024-01-18T22:04:33.451Z,1705615473.451 [ballast_and_trim:Science:ChlThreshTrigger] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:ChlThreshTrigger
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Uninitialize.
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2024-01-18T22:04:33.452Z,1705615473.452 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectOil] Stopped
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2024-01-18T22:04:33.457Z,1705615473.457 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectChl] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2024-01-18T22:04:33.458Z,1705615473.458 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2024-01-18T22:04:33.459Z,1705615473.459 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2024-01-18T22:04:33.459Z,1705615473.459 [ballast_and_trim:Science:Read_Oil] Stopped
2024-01-18T22:04:33.459Z,1705615473.459 [ballast_and_trim:Science:F] Stopped
2024-01-18T22:04:33.459Z,1705615473.459 [ballast_and_trim:Science:E] Running Loop=1
2024-01-18T22:04:33.460Z,1705615473.460 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2024-01-18T22:04:33.460Z,1705615473.460 [ballast_and_trim:Science:D] Stopped
2024-01-18T22:04:33.460Z,1705615473.460 [ballast_and_trim:Science:C] Running Loop=1
2024-01-18T22:04:33.460Z,1705615473.460 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2024-01-18T22:04:33.465Z,1705615473.465 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2024-01-18T22:04:33.465Z,1705615473.465 [ballast_and_trim:Science:B] Running Loop=1
2024-01-18T22:04:33.466Z,1705615473.466 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2024-01-18T22:04:33.467Z,1705615473.467 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2024-01-18T22:04:33.467Z,1705615473.467 [ballast_and_trim:Science:A] Stopped
2024-01-18T22:04:33.746Z,1705615473.746 [WetLabsBB2FL](INFO): Powering up
2024-01-18T22:04:33.824Z,1705615473.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2024-01-18T22:04:33.824Z,1705615473.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2024-01-18T22:04:33.824Z,1705615473.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2024-01-18T22:04:33.833Z,1705615473.833 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2024-01-18T22:04:33.833Z,1705615473.833 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2024-01-18T22:04:33.833Z,1705615473.833 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2024-01-18T22:04:33.833Z,1705615473.833 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2024-01-18T22:04:33.833Z,1705615473.833 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2024-01-18T22:04:33.835Z,1705615473.835 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2024-01-18T22:04:33.836Z,1705615473.836 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2024-01-18T22:04:33.837Z,1705615473.837 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2024-01-18T22:04:33.837Z,1705615473.837 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2024-01-18T22:04:33.837Z,1705615473.837 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2024-01-18T22:04:33.837Z,1705615473.837 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2024-01-18T22:04:33.838Z,1705615473.838 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2024-01-18T22:04:33.838Z,1705615473.838 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2024-01-18T22:04:34.203Z,1705615474.203 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2024-01-18T22:04:34.619Z,1705615474.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2024-01-18T22:04:34.620Z,1705615474.620 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2024-01-18T22:04:35.019Z,1705615475.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2024-01-18T22:04:35.019Z,1705615475.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2024-01-18T22:04:35.019Z,1705615475.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2024-01-18T22:04:35.020Z,1705615475.020 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2024-01-18T22:04:35.020Z,1705615475.020 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2024-01-18T22:04:37.326Z,1705615477.326 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2024-01-18T22:04:39.335Z,1705615479.335 [CTD_Seabird](ERROR): Salinity reading out of range: 6.047696 psu
2024-01-18T22:04:39.338Z,1705615479.338 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:06:24.333Z,1705615584.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:06:55.457Z,1705615615.457 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:07:10.265Z,1705615630.265 [Radio_Surface](INFO): Powering down
2024-01-18T22:07:26.637Z,1705615646.637 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:07:27.641Z,1705615647.641 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2024-01-18T22:08:02.782Z,1705615682.782 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.774109
2024-01-18T22:08:22.079Z,1705615702.079 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2024-01-18T22:08:22.080Z,1705615702.080 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2024-01-18T22:08:22.080Z,1705615702.080 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2024-01-18T22:08:22.080Z,1705615702.080 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2024-01-18T22:08:22.080Z,1705615702.080 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2024-01-18T22:08:22.080Z,1705615702.080 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2024-01-18T22:08:22.081Z,1705615702.081 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2024-01-18T22:08:22.082Z,1705615702.082 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2024-01-18T22:08:22.082Z,1705615702.082 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2024-01-18T22:08:22.082Z,1705615702.082 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2024-01-18T22:08:22.082Z,1705615702.082 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2024-01-18T22:08:22.467Z,1705615702.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.041588 m 
2024-01-18T22:08:22.467Z,1705615702.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2024-01-18T22:08:22.467Z,1705615702.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2024-01-18T22:08:22.467Z,1705615702.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:08:22.467Z,1705615702.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2024-01-18T22:08:22.468Z,1705615702.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2024-01-18T22:18:23.225Z,1705616303.225 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2024-01-18T22:18:23.225Z,1705616303.225 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2024-01-18T22:18:23.225Z,1705616303.225 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:18:23.225Z,1705616303.225 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute] Running Loop=1
2024-01-18T22:18:23.631Z,1705616303.631 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute](INFO): Executing command gfscan
2024-01-18T22:18:23.631Z,1705616303.631 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E.Execute] Stopped
2024-01-18T22:18:23.632Z,1705616303.632 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F] Running Loop=1
2024-01-18T22:18:23.674Z,1705616303.674 [CommandExec](IMPORTANT): got command gfscan
2024-01-18T22:18:24.039Z,1705616304.039 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F](INFO): Running ballast and trim. Depth = 6.549398 m 
2024-01-18T22:18:24.039Z,1705616304.039 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F] Stopped
2024-01-18T22:18:24.039Z,1705616304.039 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.] Running Loop=1
2024-01-18T22:18:24.039Z,1705616304.039 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](INFO): Initializing BallastAndTrim.
2024-01-18T22:18:24.060Z,1705616304.060 [CBIT](IMPORTANT): Beginning ground fault scan
2024-01-18T22:18:24.727Z,1705616304.727 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:24.728Z,1705616304.728 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:25.731Z,1705616305.731 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:25.732Z,1705616305.732 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:26.736Z,1705616306.736 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:26.738Z,1705616306.738 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:26.945Z,1705616306.945 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2024-01-18T22:18:27.739Z,1705616307.739 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:27.740Z,1705616307.740 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:28.742Z,1705616308.742 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:28.744Z,1705616308.744 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:29.747Z,1705616309.747 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:29.748Z,1705616309.748 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:30.750Z,1705616310.750 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:30.752Z,1705616310.752 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:31.755Z,1705616311.755 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:31.757Z,1705616311.757 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:32.758Z,1705616312.758 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:32.760Z,1705616312.760 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:33.763Z,1705616313.763 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:33.764Z,1705616313.764 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:34.766Z,1705616314.766 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid.
2024-01-18T22:18:34.768Z,1705616314.768 [CTD_Seabird](INFO): some bad data, not updating bins
2024-01-18T22:18:34.990Z,1705616314.990 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002373
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.002413
CHAN A3 (5V): -0.001297
CHAN B0 (3.3V): -0.000275
CHAN B1 (3.15aV): -0.000019
CHAN B2 (3.15bV): -0.000381
CHAN B3 (GND): 0.000391
OPEN: -0.000020
Full Scale: +/- 1 mA
2024-01-18T22:44:04.952Z,1705617844.952 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): BallastAndTrim completed. Estimation time: 25.68 minutes.
2024-01-18T22:44:04.953Z,1705617844.953 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Estimated buoyancyNeutral: 225.376485 +/- 14.998570 cc (conf. level 99.90%, sigma: 28.453651 cc).
2024-01-18T22:44:04.954Z,1705617844.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Estimated massDefault: -10.190665 +/- 0.202418 mm (conf. level 99.90%, sigma: 0.384005 mm).
2024-01-18T22:44:04.955Z,1705617844.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Changing persisted config values to: 225.376485 cc buoyancy neutral and -10.190665 mm mass default
2024-01-18T22:44:04.960Z,1705617844.960 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): DAT.loadAtStartup=0 bool;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2024-01-18T22:44:04.961Z,1705617844.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): ThrusterServo.currLimit=50 percent;

2024-01-18T22:44:04.962Z,1705617844.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): VerticalControl.buoyancyNeutral=225.376485 cubic_centimeter;

2024-01-18T22:44:04.962Z,1705617844.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](IMPORTANT): VerticalControl.massDefault=-10.190665 millimeter;

2024-01-18T22:44:04.962Z,1705617844.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.] Stopped
2024-01-18T22:44:04.962Z,1705617844.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:G.](INFO): Uninitializing BallastAndTrim.
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2024-01-18T22:44:04.963Z,1705617844.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2024-01-18T22:44:04.965Z,1705617844.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2024-01-18T22:44:05.365Z,1705617845.365 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2024-01-18T22:44:05.366Z,1705617845.366 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2024-01-18T22:44:05.757Z,1705617845.757 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2024-01-18T22:44:05.758Z,1705617845.758 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2024-01-18T22:44:05.758Z,1705617845.758 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2024-01-18T22:44:05.758Z,1705617845.758 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2024-01-18T22:44:05.758Z,1705617845.758 [ballast_and_trim:RunBallastAndTrim] Stopped
2024-01-18T22:44:05.758Z,1705617845.758 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up] Running Loop=1
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2024-01-18T22:44:05.759Z,1705617845.759 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:44:06.162Z,1705617846.162 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up] Stopped
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up:B.Wait] Stopped
2024-01-18T22:45:48.782Z,1705617948.782 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:45:48.784Z,1705617948.784 [ballast_and_trim](INFO): Completed ballast_and_trim
2024-01-18T22:45:48.784Z,1705617948.784 [MissionManager](INFO): ballast_and_trim is completed.
2024-01-18T22:45:48.784Z,1705617948.784 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2024-01-18T22:45:48.784Z,1705617948.784 [ballast_and_trim] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:B] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:C] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:E] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:OceanCurrent] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2024-01-18T22:45:48.785Z,1705617948.785 [ballast_and_trim:BackseatDriver] Stopped
2024-01-18T22:45:48.786Z,1705617948.786 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::uninitialize ballast_and_trim:BackseatDriver
2024-01-18T22:45:48.786Z,1705617948.786 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Stopped
2024-01-18T22:45:49.199Z,1705617949.199 [MissionManager](IMPORTANT): Started mission Default
2024-01-18T22:45:49.200Z,1705617949.200 [Default] Running Loop=1
2024-01-18T22:45:49.200Z,1705617949.200 [Default](DEBUG): Aggregate::initialize Default
2024-01-18T22:45:49.200Z,1705617949.200 [Default:B.GoToSurface] Running Loop=1
2024-01-18T22:45:49.200Z,1705617949.200 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-01-18T22:45:49.200Z,1705617949.200 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-01-18T22:45:49.200Z,1705617949.200 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-01-18T22:45:49.201Z,1705617949.201 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-01-18T22:45:49.201Z,1705617949.201 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-01-18T22:45:49.202Z,1705617949.202 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-01-18T22:45:49.202Z,1705617949.202 [Default:A.Wait] Running Loop=1
2024-01-18T22:45:49.202Z,1705617949.202 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:45:49.265Z,1705617949.265 [WetLabsBB2FL](INFO): Powering down
2024-01-18T22:45:49.585Z,1705617949.585 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm (1 active estimators).
2024-01-18T22:45:49.741Z,1705617949.741 [Radio_Surface](INFO): Powering up
2024-01-18T22:45:55.253Z,1705617955.253 [DataOverHttps](INFO): Radio surface powered ON.
2024-01-18T22:46:02.509Z,1705617962.509 [Default:A.Wait](INFO): Done Waiting.
2024-01-18T22:46:02.509Z,1705617962.509 [Default:A.Wait] Stopped
2024-01-18T22:46:02.509Z,1705617962.509 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:46:06.557Z,1705617966.557 [Default:CheckIn] Running Loop=1
2024-01-18T22:46:06.558Z,1705617966.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T22:46:06.558Z,1705617966.558 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T22:46:25.373Z,1705617985.373 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:46:39.694Z,1705617999.694 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 6.
2024-01-18T22:46:39.701Z,1705617999.701 [BPC1](INFO): Received data from all battery sticks.
2024-01-18T22:46:56.497Z,1705618016.497 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:47:27.621Z,1705618047.621 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:47:58.749Z,1705618078.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:48:29.889Z,1705618109.889 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:49:01.029Z,1705618141.029 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T22:49:32.757Z,1705618172.757 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003020
2024-01-18T22:50:16.660Z,1705618216.660 [NAL9602](INFO): SBD MO Status=0, MOMSN=46282, MT Status=0, MTMSN=0
2024-01-18T22:50:16.660Z,1705618216.660 [NAL9602](INFO): No messages in MT queue
2024-01-18T22:50:17.863Z,1705618217.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225017.00,A,3648.16299,N,12147.28238,W,0.525,141.74,180124,,,A*7A
2024-01-18T22:50:17.866Z,1705618217.866 [NAL9602](INFO): GPS fix at 20240118T225017: (36.802717, -121.788040)
2024-01-18T22:50:17.885Z,1705618217.885 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T22:50:17.885Z,1705618217.885 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T22:50:33.680Z,1705618233.680 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20240118T213454/Courier0013.lzma
2024-01-18T22:50:34.683Z,1705618234.683 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0013.lzma.bak
2024-01-18T22:50:34.683Z,1705618234.683 [DataOverHttps](INFO): SBD MOMSN=19164324
2024-01-18T22:50:50.146Z,1705618250.146 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T22:50:52.967Z,1705618252.967 [DataOverHttps](INFO): Sending 1394 bytes from file Logs/20240118T213454/Express0014.lzma
2024-01-18T22:50:53.967Z,1705618253.967 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0014.lzma.bak
2024-01-18T22:50:53.967Z,1705618253.967 [DataOverHttps](INFO): SBD MOMSN=19164327
2024-01-18T22:51:11.024Z,1705618271.024 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240118T213454/Express0017.lzma
2024-01-18T22:51:12.027Z,1705618272.027 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0017.lzma.bak
2024-01-18T22:51:12.027Z,1705618272.027 [DataOverHttps](INFO): SBD MOMSN=19164355
2024-01-18T22:51:13.189Z,1705618273.189 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T22:51:13.189Z,1705618273.189 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T22:51:13.189Z,1705618273.189 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:56:13.951Z,1705618573.951 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T22:56:13.951Z,1705618573.951 [Default:CheckIn:C.Wait] Stopped
2024-01-18T22:56:13.951Z,1705618573.951 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:56:13.951Z,1705618573.951 [Default:CheckIn:D] Running Loop=1
2024-01-18T22:56:14.360Z,1705618574.360 [Default:CheckIn:D] Stopped
2024-01-18T22:56:14.360Z,1705618574.360 [Default:CheckIn:E] Running Loop=1
2024-01-18T22:56:14.760Z,1705618574.760 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.419341 min 
2024-01-18T22:56:14.760Z,1705618574.760 [Default:CheckIn:E] Stopped
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn] Stopped
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn](INFO): Running loop #2
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn] Running Loop=2
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T22:56:14.761Z,1705618574.761 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T22:56:16.772Z,1705618576.772 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225616.00,A,3648.16364,N,12147.28535,W,0.272,328.13,180124,,,A*7D
2024-01-18T22:56:16.774Z,1705618576.774 [NAL9602](INFO): GPS fix at 20240118T225616: (36.802727, -121.788089)
2024-01-18T22:56:16.807Z,1705618576.807 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T22:56:16.807Z,1705618576.807 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T22:56:26.960Z,1705618586.960 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240118T213454/Courier0019.lzma
2024-01-18T22:56:27.963Z,1705618587.963 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0019.lzma.bak
2024-01-18T22:56:27.963Z,1705618587.963 [DataOverHttps](INFO): SBD MOMSN=19164358
2024-01-18T22:56:43.984Z,1705618603.984 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20240118T213454/Express0020.lzma
2024-01-18T22:56:44.987Z,1705618604.987 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0020.lzma.bak
2024-01-18T22:56:44.987Z,1705618604.987 [DataOverHttps](INFO): SBD MOMSN=19164361
2024-01-18T22:56:46.401Z,1705618606.401 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T22:56:46.401Z,1705618606.401 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T22:56:46.401Z,1705618606.401 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T22:59:25.318Z,1705618765.318 [DataOverHttps](IMPORTANT): SBD MTMSN=20240118T225924
2024-01-18T22:59:32.652Z,1705618772.652 [DataOverHttps](INFO): Received command: load Insert/SampleAtDepth.tl;set SampleAtDepth.MaxWaitNotReachingDepth 15 min;run
2024-01-18T22:59:32.699Z,1705618772.699 [CommandExec](IMPORTANT): got command load ./Missions/Insert/SampleAtDepth.tl
2024-01-18T22:59:32.700Z,1705618772.700 [MissionManager](INFO): Loading Mission from file: ./Missions/Insert/SampleAtDepth.tl
2024-01-18T22:59:32.701Z,1705618772.701 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Insert/SampleAtDepth.tx
2024-01-18T22:59:32.790Z,1705618772.790 [MissionManager](INFO): DefineArg SampleAtDepth.TargetDepth = 5.000000 m
2024-01-18T22:59:32.793Z,1705618772.793 [MissionManager](INFO): DefineArg SampleAtDepth.SettleTime = 10.000000 s
2024-01-18T22:59:32.796Z,1705618772.796 [MissionManager](INFO): DefineArg SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2024-01-18T22:59:32.799Z,1705618772.799 [MissionManager](INFO): DefineArg SampleAtDepth.RotateOnly = 0.000000 bool
2024-01-18T22:59:32.803Z,1705618772.803 [MissionManager](INFO): DefineArg SampleAtDepth.UseCANONSampler = 1 bool
2024-01-18T22:59:32.807Z,1705618772.807 [MissionManager](INFO): DefineArg SampleAtDepth.UseESP = 0 bool
2024-01-18T22:59:32.811Z,1705618772.811 [MissionManager](INFO): DefineArg SampleAtDepth.ESPCartridgeType = nan count
2024-01-18T22:59:32.814Z,1705618772.814 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTriggerTimeout = 3.000000 min
2024-01-18T22:59:32.819Z,1705618772.819 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2024-01-18T22:59:32.823Z,1705618772.823 [MissionManager](INFO): DefineArg SampleAtDepth.BuoyancyNeutral = 384.168365 cc
2024-01-18T22:59:32.866Z,1705618772.866 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Construct.
2024-01-18T22:59:32.872Z,1705618772.872 [SampleAtDepth:sample:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-01-18T22:59:32.893Z,1705618772.893 [SampleAtDepth:sample:SampleWrapper:A.Pitch](DEBUG): Construct.
2024-01-18T22:59:32.900Z,1705618772.900 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2024-01-18T22:59:32.930Z,1705618772.930 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-01-18T22:59:32.946Z,1705618772.946 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2024-01-18T22:59:32.946Z,1705618772.946 [MissionManager](ERROR): Slate does not contain celsius
2024-01-18T22:59:32.951Z,1705618772.951 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-01-18T22:59:32.955Z,1705618772.955 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](DEBUG): Construct.
2024-01-18T22:59:33.051Z,1705618773.051 [MissionManager](DEBUG): 
aggregate SampleAtDepth {
  """
  Take a water sample at a specified depth.
  """

  arguments {
    TargetDepth = 5 meter
      """
      Depth to sample at. Initialized to 5 m.
      """

    SettleTime = 10 second
      """
      Time to wait after reaching target depth before triggering sample.
      Initialized to 10 minutes.
      """

    MaxWaitNotReachingDepth = 3 hour
      """
      Maximum wait time the vehicle cannot reach the targeted depth.
      Initialized to 3 hours.
      """

    RotateOnly = 0 bool

    UseCANONSampler = Science:CANONSampler.loadAtStartup
      """
      Whether to use CANON Sampler to sample.
      """

    UseESP = Science:ESPComponent.loadAtStartup
      """
      Whether to use ESP to sample.
      """

    ESPCartridgeType = NaN count
      """
      Specifies ESP cartridge type code.
      """

    CANONSamplerTriggerTimeout = 3 minute
      """
      How long to wait for a CANON Sampler sample to start.
      """

    CANONSamplerTimeout = Science:CANONSampler.sampleTimeout
      """
      How long to wait for a CANON Sampler sample to complete.
      """

    BuoyancyNeutral = Control:VerticalControl.buoyancyNeutral
      """
      Buoyancy bladder position during spiral or donut. Defaults to
      buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
      for active buoyancy
      """
  }

  run when ( called )

  aggregate ReportInvalidDepth {
    run in sequence

    break if ( not ( isNaN ( TargetDepth ) ) )

    syslog fault "SampleAtDepth received an invalid target depth. Skipping sample."
  }

  aggregate sample {
    run in sequence

    break if ( isNaN ( TargetDepth ) )

    aggregate ApproachDepth {
      run in sequence

      syslog "Moving to " + TargetDepth~meter

      behavior Guidance:Pitch {
        run in sequence

        timeout duration=MaxWaitNotReachingDepth {
          syslog important "Timed out trying to reach the targeted depth. Stopping mission."

          behavior Guidance:Execute {
            run in sequence

            set command = "stop"
          }
        }

        set depth = TargetDepth
      }
    }

    aggregate SampleWrapper {
      run in sequence

      behavior Guidance:Pitch {
        run in parallel

        set depth = TargetDepth
      }

      syslog important "At " + Universal:depth~meter + ", settling for " + SettleTime~minute

      behavior Guidance:Wait {
        run in sequence

        set duration = SettleTime
      }

      aggregate SampleCANONSampler {
        run in sequence

        break if ( not ( UseCANONSampler ) )

        assign in parallel Science:CANONSampler.sampleTimeout = CANONSamplerTimeout

        assign in parallel Science:CANONSampler.rotateOnly = RotateOnly

        readDatum id="TriggerCANONSampler" {
          timeout duration=CANONSamplerTriggerTimeout {
            syslog important "Timed out triggering CANONSampler. Stopping mission."

            behavior Guidance:Execute {
              run in sequence

              set command = "stop"
            }
          }

          Science:CANONSampler.sampling
        }

        syslog important "CANONSampler sampling at " + Universal:depth~meter + " in "
             + Science:CTD_NeilBrown.bin_mean_sea_water_temperature~celsius + " water with "
             + Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
             + " chlorophyll fluorescence."

        readDatum {
          timeout duration=CANONSamplerTimeout {
            syslog important "Timed out sampling with CANONSampler. Stopping mission."

            behavior Guidance:Execute {
              run in sequence

              set command = "stop"
            }
          }

          Science:CANONSampler.sample_number
        }
      }

      aggregate SampleESP {
        run in sequence

        break if ( not ( UseESP ) )

        aggregate SelectESPCartridge {
          run in sequence

          break if ( isNaN ( ESPCartridgeType ) )

          behavior Science:ESPCartridgeSelect {
            run in sequence

            timeout duration=P1M

            set cartridgeType = ESPCartridgeType
          }
        }

        readDatum id="TriggerESP" {
          Science:ESPComponent.sampling
        }

        syslog important "ESP sampling at " + Universal:depth~meter + " in "
             + Science:CTD_Seabird.bin_mean_sea_water_temperature~celsius + " water with "
             + Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
             + "chlorophyll fluorescence."

        readDatum id="WaitForESP" {
          Science:ESPComponent.sample_number
        }
      }
    }
  }
}


2024-01-18T22:59:33.051Z,1705618773.051 [CommandExec](IMPORTANT): Loaded ./Missions/Insert/SampleAtDepth.tl
2024-01-18T22:59:36.494Z,1705618776.494 [CommandExec](IMPORTANT): got command set SampleAtDepth.MaxWaitNotReachingDepth 15 minute
2024-01-18T22:59:36.495Z,1705618776.495 [CommandExec](IMPORTANT): got command run
2024-01-18T22:59:36.496Z,1705618776.496 [CommandExec](IMPORTANT): Running 
2024-01-18T22:59:36.634Z,1705618776.634 [Default] Stopped
2024-01-18T22:59:36.634Z,1705618776.634 [Default](DEBUG): Aggregate::uninitialize Default
2024-01-18T22:59:36.634Z,1705618776.634 [Default:B.GoToSurface] Stopped
2024-01-18T22:59:36.634Z,1705618776.634 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-01-18T22:59:36.634Z,1705618776.634 [Default:CheckIn] Stopped
2024-01-18T22:59:36.634Z,1705618776.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T22:59:36.634Z,1705618776.634 [Default:CheckIn:C.Wait] Stopped
2024-01-18T22:59:36.634Z,1705618776.634 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T22:59:36.634Z,1705618776.634 [MissionManager](IMPORTANT): Started mission SampleAtDepth
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth] Running Loop=1
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth](DEBUG): Aggregate::initialize SampleAtDepth
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth] Running Loop=1
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::initialize SampleAtDepth:ReportInvalidDepth
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth:A] Running Loop=1
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth] Stopped
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:ReportInvalidDepth
2024-01-18T22:59:36.635Z,1705618776.635 [SampleAtDepth:ReportInvalidDepth:A] Stopped
2024-01-18T22:59:36.636Z,1705618776.636 [SampleAtDepth:sample] Running Loop=1
2024-01-18T22:59:36.636Z,1705618776.636 [SampleAtDepth:sample](DEBUG): Aggregate::initialize SampleAtDepth:sample
2024-01-18T22:59:36.636Z,1705618776.636 [SampleAtDepth:sample:ApproachDepth] Running Loop=1
2024-01-18T22:59:36.636Z,1705618776.636 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::initialize SampleAtDepth:sample:ApproachDepth
2024-01-18T22:59:36.636Z,1705618776.636 [SampleAtDepth:sample:ApproachDepth:A] Running Loop=1
2024-01-18T22:59:37.042Z,1705618777.042 [SampleAtDepth:sample:ApproachDepth:A](INFO): Moving to 5.000000 m 
2024-01-18T22:59:37.042Z,1705618777.042 [SampleAtDepth:sample:ApproachDepth:A] Stopped
2024-01-18T22:59:37.042Z,1705618777.042 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Running Loop=1
2024-01-18T22:59:37.042Z,1705618777.042 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Initialize.
2024-01-18T23:00:29.547Z,1705618829.547 [NAL9602](INFO): SBD MO Status=2, MOMSN=46283, MT Status=2, MTMSN=0
2024-01-18T23:00:29.548Z,1705618829.548 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-01-18T23:01:19.246Z,1705618879.246 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T23:01:28.229Z,1705618888.229 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:01:49.946Z,1705618909.946 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T23:01:52.485Z,1705618912.485 [Radio_Surface](INFO): Powering down
2024-01-18T23:01:59.357Z,1705618919.357 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:02:00.361Z,1705618920.361 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2024-01-18T23:02:21.473Z,1705618941.473 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Stopped
2024-01-18T23:02:21.474Z,1705618941.474 [SampleAtDepth:sample:ApproachDepth](INFO): Completed SampleAtDepth:sample:ApproachDepth
2024-01-18T23:02:21.474Z,1705618941.474 [SampleAtDepth:sample:ApproachDepth] Stopped
2024-01-18T23:02:21.474Z,1705618941.474 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:ApproachDepth
2024-01-18T23:02:21.474Z,1705618941.474 [SampleAtDepth:sample:SampleWrapper] Running Loop=1
2024-01-18T23:02:21.474Z,1705618941.474 [SampleAtDepth:sample:SampleWrapper](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper
2024-01-18T23:02:21.476Z,1705618941.476 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Running Loop=1
2024-01-18T23:02:21.476Z,1705618941.476 [SampleAtDepth:sample:SampleWrapper:A.Pitch](DEBUG): Initialize.
2024-01-18T23:02:21.477Z,1705618941.477 [SampleAtDepth:sample:SampleWrapper:B] Running Loop=1
2024-01-18T23:02:21.881Z,1705618941.881 [SampleAtDepth:sample:SampleWrapper:B](IMPORTANT): At 5.026029 m , settling for 0.166667 min 
2024-01-18T23:02:21.881Z,1705618941.881 [SampleAtDepth:sample:SampleWrapper:B] Stopped
2024-01-18T23:02:21.881Z,1705618941.881 [SampleAtDepth:sample:SampleWrapper:C.Wait] Running Loop=1
2024-01-18T23:02:21.881Z,1705618941.881 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:02:21.881Z,1705618941.881 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Running Loop=1
2024-01-18T23:02:32.376Z,1705618952.376 [SampleAtDepth:sample:SampleWrapper:C.Wait](INFO): Done Waiting.
2024-01-18T23:02:32.376Z,1705618952.376 [SampleAtDepth:sample:SampleWrapper:C.Wait] Stopped
2024-01-18T23:02:32.376Z,1705618952.376 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:02:32.377Z,1705618952.377 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler] Running Loop=1
2024-01-18T23:02:32.377Z,1705618952.377 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-01-18T23:02:32.377Z,1705618952.377 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2024-01-18T23:02:32.377Z,1705618952.377 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2024-01-18T23:02:32.377Z,1705618952.377 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2024-01-18T23:02:32.782Z,1705618952.782 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sampling
2024-01-18T23:02:32.783Z,1705618952.783 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2024-01-18T23:02:32.783Z,1705618952.783 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2024-01-18T23:02:33.580Z,1705618953.580 [CANONSampler](INFO): Powering up
2024-01-18T23:03:34.607Z,1705619014.607 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2024-01-18T23:03:34.607Z,1705619014.607 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D] Running Loop=1
2024-01-18T23:03:34.983Z,1705619014.983 [CANONSampler](INFO): �P��

2024-01-18T23:03:34.984Z,1705619014.984 [CANONSampler](INFO): �5A1I�TWITTER 2.0

2024-01-18T23:03:34.984Z,1705619014.984 [CANONSampler](INFO): Last pos=0, UI[4]=3900

2024-01-18T23:03:34.985Z,1705619014.985 [CANONSampler](INFO): S>S

2024-01-18T23:03:34.985Z,1705619014.985 [CANONSampler](INFO): MO=0

2024-01-18T23:03:34.986Z,1705619014.986 [CANONSampler](INFO): ELMO will go to position 1

2024-01-18T23:03:35.039Z,1705619015.039 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2024-01-18T23:03:35.039Z,1705619015.039 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D](IMPORTANT): CANONSampler sampling at 7.778137 m inwater with nan ug/l chlorophyll fluorescence.
2024-01-18T23:03:35.039Z,1705619015.039 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D] Stopped
2024-01-18T23:03:35.039Z,1705619015.039 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E] Running Loop=1
2024-01-18T23:03:35.392Z,1705619015.392 [CANONSampler](INFO): Initial cnts = 0

2024-01-18T23:03:35.392Z,1705619015.392 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2024-01-18T23:03:35.407Z,1705619015.407 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sample_number
2024-01-18T23:03:35.741Z,1705619015.741 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.723114
2024-01-18T23:03:36.600Z,1705619016.600 [CANONSampler](INFO): MO=1, MF=0, PX=195

2024-01-18T23:03:37.413Z,1705619017.413 [CANONSampler](INFO): MO=1, MF=0, PX=1274

2024-01-18T23:03:38.620Z,1705619018.620 [CANONSampler](INFO): MO=1, MF=0, PX=2520

2024-01-18T23:03:39.426Z,1705619019.426 [CANONSampler](INFO): MO=1, MF=0, PX=3767

2024-01-18T23:03:40.639Z,1705619020.639 [CANONSampler](INFO): MO=1, MF=0, PX=5013

2024-01-18T23:03:41.857Z,1705619021.857 [CANONSampler](INFO): MO=1, MF=0, PX=6259

2024-01-18T23:03:42.660Z,1705619022.660 [CANONSampler](INFO): MO=1, MF=0, PX=7505

2024-01-18T23:03:43.872Z,1705619023.872 [CANONSampler](INFO): MO=1, MF=0, PX=8750

2024-01-18T23:03:44.678Z,1705619024.678 [CANONSampler](INFO): MO=1, MF=0, PX=9996

2024-01-18T23:03:45.895Z,1705619025.895 [CANONSampler](INFO): MO=1, MF=0, PX=11242

2024-01-18T23:03:46.701Z,1705619026.701 [CANONSampler](INFO): MO=1, MF=0, PX=12493

2024-01-18T23:03:47.911Z,1705619027.911 [CANONSampler](INFO): MO=1, MF=0, PX=13744

2024-01-18T23:03:49.127Z,1705619029.127 [CANONSampler](INFO): MO=1, MF=0, PX=14996

2024-01-18T23:03:49.944Z,1705619029.944 [CANONSampler](INFO): MO=1, MF=0, PX=16247

2024-01-18T23:03:51.145Z,1705619031.145 [CANONSampler](INFO): MO=1, MF=0, PX=17498

2024-01-18T23:03:51.952Z,1705619031.952 [CANONSampler](INFO): MO=1, MF=0, PX=18749

2024-01-18T23:03:53.167Z,1705619033.167 [CANONSampler](INFO): MO=1, MF=0, PX=20000

2024-01-18T23:03:54.379Z,1705619034.379 [CANONSampler](INFO): MO=1, MF=0, PX=21251

2024-01-18T23:03:55.182Z,1705619035.182 [CANONSampler](INFO): MO=1, MF=0, PX=22502

2024-01-18T23:03:56.395Z,1705619036.395 [CANONSampler](INFO): MO=1, MF=0, PX=23754

2024-01-18T23:03:57.210Z,1705619037.210 [CANONSampler](INFO): MO=1, MF=0, PX=25005

2024-01-18T23:03:58.420Z,1705619038.420 [CANONSampler](INFO): MO=1, MF=0, PX=26256

2024-01-18T23:03:59.628Z,1705619039.628 [CANONSampler](INFO): MO=1, MF=0, PX=27507

2024-01-18T23:04:00.446Z,1705619040.446 [CANONSampler](INFO): MO=1, MF=0, PX=28758

2024-01-18T23:04:01.655Z,1705619041.655 [CANONSampler](INFO): MO=0, MF=0, PX=29809

2024-01-18T23:04:09.340Z,1705619049.340 [CANONSampler](INFO):  DONE with MO=0, MF=0!

2024-01-18T23:05:01.443Z,1705619101.443 [CANONSampler](INFO): Pumping DONE

2024-01-18T23:05:11.543Z,1705619111.543 [CANONSampler](INFO): MO=0

2024-01-18T23:05:11.544Z,1705619111.544 [CANONSampler](INFO): ELMO ADVANCING to pos 1

2024-01-18T23:05:11.544Z,1705619111.544 [CANONSampler](INFO): Sending: XQ##Adv(1)


2024-01-18T23:05:11.545Z,1705619111.545 [CANONSampler](INFO): Initial cnts = 0

2024-01-18T23:05:11.545Z,1705619111.545 [CANONSampler](INFO): ADVANCING...

2024-01-18T23:05:12.753Z,1705619112.753 [CANONSampler](INFO): MO=1 MF=0 PX=183

2024-01-18T23:05:13.967Z,1705619113.967 [CANONSampler](INFO): MO=1 MF=0 PX=1344

2024-01-18T23:05:14.770Z,1705619114.770 [CANONSampler](INFO): MO=1 MF=0 PX=3267

2024-01-18T23:05:15.988Z,1705619115.988 [CANONSampler](INFO): MO=0 MF=0 PX=4030

2024-01-18T23:05:16.004Z,1705619116.004 [CANONSampler](INFO): DONE ADVANCING UI[1]=0 MO=0 MF=0 PX=4030

2024-01-18T23:05:16.795Z,1705619116.795 [CANONSampler](INFO): Saving.... DONE

2024-01-18T23:07:16.779Z,1705619236.779 [CANONSampler](INFO): Pumping DONE

2024-01-18T23:07:16.780Z,1705619236.780 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=4030

2024-01-18T23:07:17.995Z,1705619237.995 [CANONSampler](INFO): MO=1, MF=0, PX=4234

2024-01-18T23:07:18.805Z,1705619238.805 [CANONSampler](INFO): MO=1, MF=0, PX=5327

2024-01-18T23:07:20.011Z,1705619240.011 [CANONSampler](INFO): MO=1, MF=0, PX=6572

2024-01-18T23:07:21.222Z,1705619241.222 [CANONSampler](INFO): MO=1, MF=0, PX=7819

2024-01-18T23:07:22.036Z,1705619242.036 [CANONSampler](INFO): MO=1, MF=0, PX=9065

2024-01-18T23:07:23.248Z,1705619243.248 [CANONSampler](INFO): MO=1, MF=0, PX=10311

2024-01-18T23:07:24.051Z,1705619244.051 [CANONSampler](INFO): MO=1, MF=0, PX=11564

2024-01-18T23:07:25.269Z,1705619245.269 [CANONSampler](INFO): MO=1, MF=0, PX=12814

2024-01-18T23:07:26.079Z,1705619246.079 [CANONSampler](INFO): MO=1, MF=0, PX=14065

2024-01-18T23:07:27.287Z,1705619247.287 [CANONSampler](INFO): MO=1, MF=0, PX=15317

2024-01-18T23:07:28.501Z,1705619248.501 [CANONSampler](INFO): MO=1, MF=0, PX=16570

2024-01-18T23:07:29.308Z,1705619249.308 [CANONSampler](INFO): MO=1, MF=0, PX=17822

2024-01-18T23:07:30.516Z,1705619250.516 [CANONSampler](INFO): MO=1, MF=0, PX=19075

2024-01-18T23:07:31.327Z,1705619251.327 [CANONSampler](INFO): MO=1, MF=0, PX=20325

2024-01-18T23:07:32.535Z,1705619252.535 [CANONSampler](INFO): MO=1, MF=0, PX=21577

2024-01-18T23:07:33.751Z,1705619253.751 [CANONSampler](INFO): MO=1, MF=0, PX=22828

2024-01-18T23:07:34.568Z,1705619254.568 [CANONSampler](INFO): MO=1, MF=0, PX=24079

2024-01-18T23:07:35.766Z,1705619255.766 [CANONSampler](INFO): MO=1, MF=0, PX=25332

2024-01-18T23:07:36.577Z,1705619256.577 [CANONSampler](INFO): MO=1, MF=0, PX=26583

2024-01-18T23:07:37.787Z,1705619257.787 [CANONSampler](INFO): MO=1, MF=0, PX=27835

2024-01-18T23:07:39.003Z,1705619259.003 [CANONSampler](INFO): MO=1, MF=0, PX=29086

2024-01-18T23:07:39.817Z,1705619259.817 [CANONSampler](INFO): MO=1, MF=0, PX=30338

2024-01-18T23:07:41.023Z,1705619261.023 [CANONSampler](INFO): MO=1, MF=0, PX=31589

2024-01-18T23:07:41.831Z,1705619261.831 [CANONSampler](INFO): MO=1, MF=0, PX=-32695

2024-01-18T23:07:43.043Z,1705619263.043 [CANONSampler](INFO): MO=1, MF=0, PX=-31443

2024-01-18T23:07:43.846Z,1705619263.846 [CANONSampler](INFO): MO=1, MF=0, PX=-30190

2024-01-18T23:07:45.064Z,1705619265.064 [CANONSampler](INFO): MO=1, MF=0, PX=-28937

2024-01-18T23:07:46.270Z,1705619266.270 [CANONSampler](INFO): MO=1, MF=0, PX=-27685

2024-01-18T23:07:47.083Z,1705619267.083 [CANONSampler](INFO): MO=1, MF=0, PX=-26433

2024-01-18T23:07:48.390Z,1705619268.390 [CANONSampler](INFO): MO=1, MF=0, PX=-25180

2024-01-18T23:07:49.103Z,1705619269.103 [CANONSampler](INFO): MO=1, MF=0, PX=-23928

2024-01-18T23:07:50.311Z,1705619270.311 [CANONSampler](INFO): MO=1, MF=0, PX=-22676

2024-01-18T23:07:51.527Z,1705619271.527 [CANONSampler](INFO): MO=1, MF=0, PX=-21423

2024-01-18T23:07:52.333Z,1705619272.333 [CANONSampler](INFO): MO=1, MF=0, PX=-20171

2024-01-18T23:07:53.545Z,1705619273.545 [CANONSampler](INFO): MO=1, MF=0, PX=-18919

2024-01-18T23:07:54.351Z,1705619274.351 [CANONSampler](INFO): MO=1, MF=0, PX=-17666

2024-01-18T23:07:55.596Z,1705619275.596 [CANONSampler](INFO): MO=1, MF=0, PX=-16414

2024-01-18T23:07:56.378Z,1705619276.378 [CANONSampler](INFO): MO=1, MF=0, PX=-15161

2024-01-18T23:07:57.582Z,1705619277.582 [CANONSampler](INFO): MO=1, MF=0, PX=-13909

2024-01-18T23:07:58.800Z,1705619278.800 [CANONSampler](INFO): MO=1, MF=0, PX=-12657

2024-01-18T23:07:59.610Z,1705619279.610 [CANONSampler](INFO): MO=1, MF=0, PX=-11404

2024-01-18T23:08:00.816Z,1705619280.816 [CANONSampler](INFO): MO=1, MF=0, PX=-10152

2024-01-18T23:08:01.623Z,1705619281.623 [CANONSampler](INFO): MO=1, MF=0, PX=-8900

2024-01-18T23:08:02.844Z,1705619282.844 [CANONSampler](INFO): MO=1, MF=0, PX=-7652

2024-01-18T23:08:04.051Z,1705619284.051 [CANONSampler](INFO): MO=1, MF=0, PX=-6405

2024-01-18T23:08:04.859Z,1705619284.859 [CANONSampler](INFO): MO=1, MF=0, PX=-5158

2024-01-18T23:08:06.075Z,1705619286.075 [CANONSampler](INFO): MO=0, MF=0, PX=-4579

2024-01-18T23:08:14.156Z,1705619294.156 [CANONSampler](INFO):  DONE with MO=0, MF=0!

2024-01-18T23:08:14.156Z,1705619294.156 [CANONSampler](INFO): Sample 1, (err_code=0)

2024-01-18T23:08:14.157Z,1705619294.157 [CANONSampler](IMPORTANT): Sample 1, (err_code=0)

2024-01-18T23:08:14.167Z,1705619294.167 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E] Stopped
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](INFO): Completed SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler] Stopped
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Stopped
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Stopped
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleESP] Running Loop=1
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleESP
2024-01-18T23:08:14.168Z,1705619294.168 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge] Running Loop=1
2024-01-18T23:08:14.169Z,1705619294.169 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge
2024-01-18T23:08:14.169Z,1705619294.169 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect] Running Loop=1
2024-01-18T23:08:14.169Z,1705619294.169 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.
2024-01-18T23:08:14.572Z,1705619294.572 [SampleAtDepth:sample:SampleWrapper:SampleESP] Stopped
2024-01-18T23:08:14.572Z,1705619294.572 [SampleAtDepth:sample:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleESP
2024-01-18T23:08:14.573Z,1705619294.573 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge] Stopped
2024-01-18T23:08:14.573Z,1705619294.573 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge
2024-01-18T23:08:14.573Z,1705619294.573 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect] Stopped
2024-01-18T23:08:14.573Z,1705619294.573 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample:SampleWrapper](INFO): Completed SampleAtDepth:sample:SampleWrapper
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample:SampleWrapper] Stopped
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample:SampleWrapper](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Stopped
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample](INFO): Completed SampleAtDepth:sample
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample] Stopped
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth:sample](DEBUG): Aggregate::uninitialize SampleAtDepth:sample
2024-01-18T23:08:14.574Z,1705619294.574 [SampleAtDepth](INFO): Completed SampleAtDepth
2024-01-18T23:08:14.575Z,1705619294.575 [MissionManager](INFO): SampleAtDepth is completed.
2024-01-18T23:08:14.575Z,1705619294.575 [MissionManager](INFO): Uninitializing Mission SampleAtDepth
2024-01-18T23:08:14.575Z,1705619294.575 [SampleAtDepth] Stopped
2024-01-18T23:08:14.575Z,1705619294.575 [SampleAtDepth](DEBUG): Aggregate::uninitialize SampleAtDepth
2024-01-18T23:08:14.955Z,1705619294.955 [CANONSampler](INFO): Powering down
2024-01-18T23:08:15.061Z,1705619295.061 [MissionManager](IMPORTANT): Started mission Default
2024-01-18T23:08:15.061Z,1705619295.061 [Default] Running Loop=1
2024-01-18T23:08:15.062Z,1705619295.062 [Default](DEBUG): Aggregate::initialize Default
2024-01-18T23:08:15.062Z,1705619295.062 [Default:B.GoToSurface] Running Loop=1
2024-01-18T23:08:15.062Z,1705619295.062 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-01-18T23:08:15.062Z,1705619295.062 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-01-18T23:08:15.062Z,1705619295.062 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-01-18T23:08:15.063Z,1705619295.063 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-01-18T23:08:15.063Z,1705619295.063 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-01-18T23:08:15.063Z,1705619295.063 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-01-18T23:08:15.063Z,1705619295.063 [Default:A.Wait] Running Loop=1
2024-01-18T23:08:15.064Z,1705619295.064 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:08:15.477Z,1705619295.477 [Radio_Surface](INFO): Powering up
2024-01-18T23:08:20.885Z,1705619300.885 [DataOverHttps](INFO): Radio surface powered ON.
2024-01-18T23:08:28.412Z,1705619308.412 [Default:A.Wait](INFO): Done Waiting.
2024-01-18T23:08:28.412Z,1705619308.412 [Default:A.Wait] Stopped
2024-01-18T23:08:28.412Z,1705619308.412 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:08:51.005Z,1705619331.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:09:22.129Z,1705619362.129 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:09:53.257Z,1705619393.257 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:10:24.382Z,1705619424.382 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:10:55.510Z,1705619455.510 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:11:26.633Z,1705619486.633 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:11:57.761Z,1705619517.761 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:12:03.672Z,1705619523.672 [Default:B.GoToSurface](ERROR): Pitch down timeout. Pitch: -27.17
2024-01-18T23:12:28.885Z,1705619548.885 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:12:37.617Z,1705619557.617 [Default:CheckIn] Running Loop=1
2024-01-18T23:12:37.618Z,1705619557.618 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:12:37.618Z,1705619557.618 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:13:00.009Z,1705619580.009 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-01-18T23:13:31.985Z,1705619611.985 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003144
2024-01-18T23:17:37.872Z,1705619857.872 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-01-18T23:12:37.6Z
2024-01-18T23:17:37.872Z,1705619857.872 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:17:37.873Z,1705619857.873 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:17:42.334Z,1705619862.334 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T23:17:47.248Z,1705619867.248 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240118T213454/Courier0022.lzma
2024-01-18T23:17:48.251Z,1705619868.251 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0022.lzma.bak
2024-01-18T23:17:48.251Z,1705619868.251 [DataOverHttps](INFO): SBD MOMSN=19164378
2024-01-18T23:18:04.506Z,1705619884.506 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20240118T213454/Express0023.lzma
2024-01-18T23:18:05.507Z,1705619885.507 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0023.lzma.bak
2024-01-18T23:18:05.508Z,1705619885.508 [DataOverHttps](INFO): SBD MOMSN=19164380
2024-01-18T23:18:13.058Z,1705619893.058 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T23:18:24.480Z,1705619904.480 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20240118T213454/Express0026.lzma
2024-01-18T23:18:25.483Z,1705619905.483 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0026.lzma.bak
2024-01-18T23:18:25.483Z,1705619905.483 [DataOverHttps](INFO): SBD MOMSN=19164395
2024-01-18T23:18:26.868Z,1705619906.868 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:18:26.877Z,1705619906.877 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:18:26.877Z,1705619906.877 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:23:27.439Z,1705620207.439 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:23:27.439Z,1705620207.439 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:23:27.439Z,1705620207.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:23:27.440Z,1705620207.440 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:23:27.850Z,1705620207.850 [Default:CheckIn:D] Stopped
2024-01-18T23:23:27.850Z,1705620207.850 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:23:28.247Z,1705620208.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.213138 min 
2024-01-18T23:23:28.247Z,1705620208.247 [Default:CheckIn:E] Stopped
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn] Stopped
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn](INFO): Running loop #2
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn] Running Loop=2
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:23:28.248Z,1705620208.248 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:23:29.858Z,1705620209.858 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-01-18T23:23:29.858Z,1705620209.858 [NAL9602] Data Fault, FailCount= 1
2024-01-18T23:23:29.858Z,1705620209.858 [NAL9602](ERROR): Data Fault
2024-01-18T23:23:29.905Z,1705620209.905 [CBIT](ERROR): Data Fault in component: NAL9602
2024-01-18T23:23:30.258Z,1705620210.258 [NAL9602](INFO): Powering down
2024-01-18T23:23:31.090Z,1705620211.090 [CBIT](INFO): Clearing failed state for component NAL9602
2024-01-18T23:23:31.090Z,1705620211.090 [NAL9602] No Fault, FailCount= 1
2024-01-18T23:24:00.562Z,1705620240.562 [NAL9602](INFO): Powering up NAL9602
2024-01-18T23:24:11.466Z,1705620251.466 [NAL9602](INFO): NAL9602 initialized
2024-01-18T23:28:28.429Z,1705620508.429 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-01-18T23:23:28.2Z
2024-01-18T23:28:28.429Z,1705620508.429 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:28:28.429Z,1705620508.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:28:36.044Z,1705620516.044 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240118T213454/Courier0028.lzma
2024-01-18T23:28:37.047Z,1705620517.047 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0028.lzma.bak
2024-01-18T23:28:37.047Z,1705620517.047 [DataOverHttps](INFO): SBD MOMSN=19164397
2024-01-18T23:28:55.922Z,1705620535.922 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20240118T213454/Express0029.lzma
2024-01-18T23:28:56.923Z,1705620536.923 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0029.lzma.bak
2024-01-18T23:28:56.923Z,1705620536.923 [DataOverHttps](INFO): SBD MOMSN=19164399
2024-01-18T23:28:58.394Z,1705620538.394 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:28:58.394Z,1705620538.394 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:28:58.394Z,1705620538.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:29:14.944Z,1705620554.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T23:29:45.646Z,1705620585.646 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T23:33:58.968Z,1705620838.968 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:33:58.968Z,1705620838.968 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:33:58.968Z,1705620838.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:33:58.969Z,1705620838.969 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:33:59.373Z,1705620839.373 [Default:CheckIn:D] Stopped
2024-01-18T23:33:59.373Z,1705620839.373 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:33:59.789Z,1705620839.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.738517 min 
2024-01-18T23:33:59.789Z,1705620839.789 [Default:CheckIn:E] Stopped
2024-01-18T23:33:59.789Z,1705620839.789 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:33:59.789Z,1705620839.789 [Default:CheckIn] Stopped
2024-01-18T23:33:59.789Z,1705620839.789 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:33:59.790Z,1705620839.790 [Default:CheckIn](INFO): Running loop #3
2024-01-18T23:33:59.790Z,1705620839.790 [Default:CheckIn] Running Loop=3
2024-01-18T23:33:59.790Z,1705620839.790 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:33:59.790Z,1705620839.790 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:34:01.788Z,1705620841.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233400.00,A,3648.16756,N,12147.28134,W,0.350,12.21,180124,,,A*45
2024-01-18T23:34:01.790Z,1705620841.790 [NAL9602](INFO): GPS fix at 20240118T233400: (36.802793, -121.788022)
2024-01-18T23:34:01.825Z,1705620841.825 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:34:01.825Z,1705620841.825 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:34:09.232Z,1705620849.232 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20240118T213454/Courier0031.lzma
2024-01-18T23:34:10.235Z,1705620850.235 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0031.lzma.bak
2024-01-18T23:34:10.235Z,1705620850.235 [DataOverHttps](INFO): SBD MOMSN=19164404
2024-01-18T23:34:28.983Z,1705620868.983 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20240118T213454/Express0032.lzma
2024-01-18T23:34:29.979Z,1705620869.979 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0032.lzma.bak
2024-01-18T23:34:29.979Z,1705620869.979 [DataOverHttps](INFO): SBD MOMSN=19164407
2024-01-18T23:34:31.358Z,1705620871.358 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:34:31.358Z,1705620871.358 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:34:31.358Z,1705620871.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:34:32.550Z,1705620872.550 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-01-18T23:34:32.625Z,1705620872.625 [NAL9602](ERROR): received: 
+CSQ:0

OK283, 2, 0, 0, 0

OK
2024-01-18T23:35:09.170Z,1705620909.170 [DataOverHttps](IMPORTANT): SBD MTMSN=20240118T233508
2024-01-18T23:35:12.542Z,1705620912.542 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2024-01-18T23:35:12.542Z,1705620912.542 [DropWeight] Hardware Fault, FailCount= 1
2024-01-18T23:35:12.542Z,1705620912.542 [DropWeight](ERROR): Hardware Fault
2024-01-18T23:35:12.617Z,1705620912.617 [CommandExec](FAULT): Scheduling is paused
2024-01-18T23:35:12.618Z,1705620912.618 [CBIT](INFO): Critical error at 20240118T233512
2024-01-18T23:35:12.618Z,1705620912.618 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2024-01-18T23:35:12.637Z,1705620912.637 [CBIT](ERROR): Hardware Fault in component: DropWeight
2024-01-18T23:35:12.637Z,1705620912.637 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2024-01-18T23:35:13.006Z,1705620913.006 [CBIT](INFO): Critical error at 20240118T233512
2024-01-18T23:35:16.664Z,1705620916.664 [DataOverHttps](INFO): Received command: failComponent
2024-01-18T23:35:16.702Z,1705620916.702 [CommandExec](IMPORTANT): got command failComponent
2024-01-18T23:35:16.702Z,1705620916.702 [CommandExec](IMPORTANT): Failed components:
2024-01-18T23:35:16.703Z,1705620916.703 [CommandExec](IMPORTANT): DropWeight: Hardware Fault
2024-01-18T23:39:04.449Z,1705621144.449 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T23:39:31.935Z,1705621171.935 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:39:31.936Z,1705621171.936 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:39:31.936Z,1705621171.936 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:39:31.936Z,1705621171.936 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:39:32.340Z,1705621172.340 [Default:CheckIn:D] Stopped
2024-01-18T23:39:32.340Z,1705621172.340 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.287978 min 
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn:E] Stopped
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn] Stopped
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:39:32.746Z,1705621172.746 [Default:CheckIn](INFO): Running loop #4
2024-01-18T23:39:32.747Z,1705621172.747 [Default:CheckIn] Running Loop=4
2024-01-18T23:39:32.747Z,1705621172.747 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:39:32.747Z,1705621172.747 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:39:34.756Z,1705621174.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233933.00,A,3648.17222,N,12147.28449,W,1.030,12.21,180124,,,A*44
2024-01-18T23:39:34.758Z,1705621174.758 [NAL9602](INFO): GPS fix at 20240118T233933: (36.802870, -121.788075)
2024-01-18T23:39:34.789Z,1705621174.789 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:39:34.789Z,1705621174.789 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:39:41.936Z,1705621181.936 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20240118T213454/Courier0034.lzma
2024-01-18T23:39:42.939Z,1705621182.939 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0034.lzma.bak
2024-01-18T23:39:42.939Z,1705621182.939 [DataOverHttps](INFO): SBD MOMSN=19164415
2024-01-18T23:39:59.493Z,1705621199.493 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20240118T213454/Express0035.lzma
2024-01-18T23:40:00.495Z,1705621200.495 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0035.lzma.bak
2024-01-18T23:40:00.495Z,1705621200.495 [DataOverHttps](INFO): SBD MOMSN=19164420
2024-01-18T23:40:01.853Z,1705621201.853 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:40:01.853Z,1705621201.853 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:40:01.853Z,1705621201.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:40:07.484Z,1705621207.484 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T23:45:02.464Z,1705621502.464 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:45:02.464Z,1705621502.464 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:45:02.465Z,1705621502.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:45:02.465Z,1705621502.465 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:45:02.855Z,1705621502.855 [Default:CheckIn:D] Stopped
2024-01-18T23:45:02.855Z,1705621502.855 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.796566 min 
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn:E] Stopped
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn] Stopped
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:45:03.314Z,1705621503.314 [Default:CheckIn](INFO): Running loop #5
2024-01-18T23:45:03.315Z,1705621503.315 [Default:CheckIn] Running Loop=5
2024-01-18T23:45:03.315Z,1705621503.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:45:03.315Z,1705621503.315 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:45:05.248Z,1705621505.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234503.00,A,3648.15808,N,12147.29108,W,5.268,12.21,180124,,,A*46
2024-01-18T23:45:05.250Z,1705621505.250 [NAL9602](INFO): GPS fix at 20240118T234503: (36.802635, -121.788185)
2024-01-18T23:45:05.286Z,1705621505.286 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:45:05.286Z,1705621505.286 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:45:12.892Z,1705621512.892 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240118T213454/Courier0039.lzma
2024-01-18T23:45:13.895Z,1705621513.895 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0039.lzma.bak
2024-01-18T23:45:13.895Z,1705621513.895 [DataOverHttps](INFO): SBD MOMSN=19164442
2024-01-18T23:45:29.864Z,1705621529.864 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20240118T213454/Express0041.lzma
2024-01-18T23:45:30.867Z,1705621530.867 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0041.lzma.bak
2024-01-18T23:45:30.867Z,1705621530.867 [DataOverHttps](INFO): SBD MOMSN=19164445
2024-01-18T23:45:32.339Z,1705621532.339 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:45:32.339Z,1705621532.339 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:45:32.339Z,1705621532.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:45:35.950Z,1705621535.950 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-01-18T23:45:36.025Z,1705621536.025 [NAL9602](ERROR): received: 
+CSQ:0

OK283, 2, 0, 0, 0

OK
2024-01-18T23:50:07.446Z,1705621807.446 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-18T23:50:12.754Z,1705621812.754 [CBIT](INFO): Clearing failed state for component DropWeight
2024-01-18T23:50:12.754Z,1705621812.754 [DropWeight] No Fault, FailCount= 1
2024-01-18T23:50:32.934Z,1705621832.934 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:50:32.934Z,1705621832.934 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:50:32.934Z,1705621832.934 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:50:32.934Z,1705621832.934 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:50:33.332Z,1705621833.332 [Default:CheckIn:D] Stopped
2024-01-18T23:50:33.332Z,1705621833.332 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:50:33.737Z,1705621833.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.304517 min 
2024-01-18T23:50:33.737Z,1705621833.737 [Default:CheckIn:E] Stopped
2024-01-18T23:50:33.737Z,1705621833.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:50:33.737Z,1705621833.737 [Default:CheckIn] Stopped
2024-01-18T23:50:33.737Z,1705621833.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:50:33.738Z,1705621833.738 [Default:CheckIn](INFO): Running loop #6
2024-01-18T23:50:33.738Z,1705621833.738 [Default:CheckIn] Running Loop=6
2024-01-18T23:50:33.738Z,1705621833.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:50:33.738Z,1705621833.738 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:50:35.745Z,1705621835.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235034.00,A,3648.16311,N,12147.29198,W,0.836,168.98,180124,,,A*75
2024-01-18T23:50:35.747Z,1705621835.747 [NAL9602](INFO): GPS fix at 20240118T235034: (36.802718, -121.788200)
2024-01-18T23:50:35.775Z,1705621835.775 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:50:35.775Z,1705621835.775 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:50:43.428Z,1705621843.428 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240118T213454/Courier0043.lzma
2024-01-18T23:50:44.431Z,1705621844.431 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0043.lzma.bak
2024-01-18T23:50:44.431Z,1705621844.431 [DataOverHttps](INFO): SBD MOMSN=19164473
2024-01-18T23:51:08.217Z,1705621868.217 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20240118T213454/Express0044.lzma
2024-01-18T23:51:08.538Z,1705621868.538 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-18T23:51:09.219Z,1705621869.219 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0044.lzma.bak
2024-01-18T23:51:09.219Z,1705621869.219 [DataOverHttps](INFO): SBD MOMSN=19164476
2024-01-18T23:51:10.570Z,1705621870.570 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:51:10.570Z,1705621870.570 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:51:10.570Z,1705621870.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:51:34.810Z,1705621894.810 [BPC1](INFO): Calculating totals. Valid battery stick count: 36. Valid reserve battery stick count: 6.
2024-01-18T23:51:34.821Z,1705621894.821 [BPC1](INFO): Received data from all battery sticks.
2024-01-18T23:56:11.128Z,1705622171.128 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-18T23:56:11.128Z,1705622171.128 [Default:CheckIn:C.Wait] Stopped
2024-01-18T23:56:11.128Z,1705622171.128 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-18T23:56:11.129Z,1705622171.129 [Default:CheckIn:D] Running Loop=1
2024-01-18T23:56:11.545Z,1705622171.545 [Default:CheckIn:D] Stopped
2024-01-18T23:56:11.545Z,1705622171.545 [Default:CheckIn:E] Running Loop=1
2024-01-18T23:56:11.935Z,1705622171.935 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.941386 min 
2024-01-18T23:56:11.935Z,1705622171.935 [Default:CheckIn:E] Stopped
2024-01-18T23:56:11.935Z,1705622171.935 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-18T23:56:11.935Z,1705622171.935 [Default:CheckIn] Stopped
2024-01-18T23:56:11.936Z,1705622171.936 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-18T23:56:11.936Z,1705622171.936 [Default:CheckIn](INFO): Running loop #7
2024-01-18T23:56:11.936Z,1705622171.936 [Default:CheckIn] Running Loop=7
2024-01-18T23:56:11.936Z,1705622171.936 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-18T23:56:11.936Z,1705622171.936 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-18T23:56:13.952Z,1705622173.952 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235612.00,A,3648.18326,N,12147.28131,W,0.369,13.07,180124,,,A*45
2024-01-18T23:56:13.954Z,1705622173.954 [NAL9602](INFO): GPS fix at 20240118T235612: (36.803054, -121.788022)
2024-01-18T23:56:13.965Z,1705622173.965 [Default:CheckIn:Read_GPS] Stopped
2024-01-18T23:56:13.965Z,1705622173.965 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-18T23:56:20.917Z,1705622180.917 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20240118T213454/Courier0046.lzma
2024-01-18T23:56:21.919Z,1705622181.919 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0046.lzma.bak
2024-01-18T23:56:21.919Z,1705622181.919 [DataOverHttps](INFO): SBD MOMSN=19164480
2024-01-18T23:56:37.708Z,1705622197.708 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20240118T213454/Express0047.lzma
2024-01-18T23:56:38.711Z,1705622198.711 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0047.lzma.bak
2024-01-18T23:56:38.711Z,1705622198.711 [DataOverHttps](INFO): SBD MOMSN=19164483
2024-01-18T23:56:40.220Z,1705622200.220 [Default:CheckIn:Read_Iridium] Stopped
2024-01-18T23:56:40.221Z,1705622200.221 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-18T23:56:40.221Z,1705622200.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-18T23:56:44.650Z,1705622204.650 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-01-18T23:56:44.725Z,1705622204.725 [NAL9602](ERROR): received: 
+CSQ:0

OK283, 2, 0, 0, 0

OK
2024-01-19T00:01:16.238Z,1705622476.238 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-19T00:01:40.888Z,1705622500.888 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-19T00:01:40.888Z,1705622500.888 [Default:CheckIn:C.Wait] Stopped
2024-01-19T00:01:40.888Z,1705622500.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-19T00:01:40.888Z,1705622500.888 [Default:CheckIn:D] Running Loop=1
2024-01-19T00:01:41.298Z,1705622501.298 [Default:CheckIn:D] Stopped
2024-01-19T00:01:41.298Z,1705622501.298 [Default:CheckIn:E] Running Loop=1
2024-01-19T00:01:41.695Z,1705622501.695 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.437276 min 
2024-01-19T00:01:41.695Z,1705622501.695 [Default:CheckIn:E] Stopped
2024-01-19T00:01:41.695Z,1705622501.695 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn] Stopped
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn](INFO): Running loop #8
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn] Running Loop=8
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-19T00:01:41.696Z,1705622501.696 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-19T00:01:46.939Z,1705622506.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000145.00,A,3648.15874,N,12147.30067,W,2.799,180.43,190124,,,A*7D
2024-01-19T00:01:46.941Z,1705622506.941 [NAL9602](INFO): GPS fix at 20240119T000145: (36.802646, -121.788344)
2024-01-19T00:01:46.952Z,1705622506.952 [Default:CheckIn:Read_GPS] Stopped
2024-01-19T00:01:46.952Z,1705622506.952 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-19T00:01:52.412Z,1705622512.412 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240118T213454/Courier0049.lzma
2024-01-19T00:01:53.415Z,1705622513.415 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0049.lzma.bak
2024-01-19T00:01:53.415Z,1705622513.415 [DataOverHttps](INFO): SBD MOMSN=19164486
2024-01-19T00:02:09.509Z,1705622529.509 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20240118T213454/Express0050.lzma
2024-01-19T00:02:10.511Z,1705622530.511 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0050.lzma.bak
2024-01-19T00:02:10.511Z,1705622530.511 [DataOverHttps](INFO): SBD MOMSN=19164489
2024-01-19T00:02:11.996Z,1705622531.996 [Default:CheckIn:Read_Iridium] Stopped
2024-01-19T00:02:11.996Z,1705622531.996 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-19T00:02:11.996Z,1705622531.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-19T00:02:19.259Z,1705622539.259 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-19T00:07:12.589Z,1705622832.589 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-19T00:07:12.589Z,1705622832.589 [Default:CheckIn:C.Wait] Stopped
2024-01-19T00:07:12.589Z,1705622832.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-19T00:07:12.590Z,1705622832.590 [Default:CheckIn:D] Running Loop=1
2024-01-19T00:07:12.990Z,1705622832.990 [Default:CheckIn:D] Stopped
2024-01-19T00:07:12.990Z,1705622832.990 [Default:CheckIn:E] Running Loop=1
2024-01-19T00:07:13.398Z,1705622833.398 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.965479 min 
2024-01-19T00:07:13.398Z,1705622833.398 [Default:CheckIn:E] Stopped
2024-01-19T00:07:13.398Z,1705622833.398 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-19T00:07:13.398Z,1705622833.398 [Default:CheckIn] Stopped
2024-01-19T00:07:13.399Z,1705622833.399 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-19T00:07:13.399Z,1705622833.399 [Default:CheckIn](INFO): Running loop #9
2024-01-19T00:07:13.399Z,1705622833.399 [Default:CheckIn] Running Loop=9
2024-01-19T00:07:13.399Z,1705622833.399 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-19T00:07:13.399Z,1705622833.399 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-19T00:07:15.391Z,1705622835.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000713.00,A,3648.18707,N,12147.27894,W,0.719,23.39,190124,,,A*43
2024-01-19T00:07:15.393Z,1705622835.393 [NAL9602](INFO): GPS fix at 20240119T000713: (36.803118, -121.787982)
2024-01-19T00:07:15.404Z,1705622835.404 [Default:CheckIn:Read_GPS] Stopped
2024-01-19T00:07:15.405Z,1705622835.405 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-19T00:07:23.144Z,1705622843.144 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240118T213454/Courier0052.lzma
2024-01-19T00:07:24.147Z,1705622844.147 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0052.lzma.bak
2024-01-19T00:07:24.147Z,1705622844.147 [DataOverHttps](INFO): SBD MOMSN=19164493
2024-01-19T00:07:40.028Z,1705622860.028 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20240118T213454/Express0053.lzma
2024-01-19T00:07:41.031Z,1705622861.031 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0053.lzma.bak
2024-01-19T00:07:41.031Z,1705622861.031 [DataOverHttps](INFO): SBD MOMSN=19164496
2024-01-19T00:07:42.481Z,1705622862.481 [Default:CheckIn:Read_Iridium] Stopped
2024-01-19T00:07:42.481Z,1705622862.481 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-19T00:07:42.481Z,1705622862.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-19T00:07:46.094Z,1705622866.094 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-01-19T00:07:46.169Z,1705622866.169 [NAL9602](ERROR): received: 
+CSQ:0

OK283, 2, 0, 0, 0

OK
2024-01-19T00:12:17.201Z,1705623137.201 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-01-19T00:12:43.080Z,1705623163.080 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-19T00:12:43.080Z,1705623163.080 [Default:CheckIn:C.Wait] Stopped
2024-01-19T00:12:43.080Z,1705623163.080 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-19T00:12:43.080Z,1705623163.080 [Default:CheckIn:D] Running Loop=1
2024-01-19T00:12:43.472Z,1705623163.472 [Default:CheckIn:D] Stopped
2024-01-19T00:12:43.472Z,1705623163.472 [Default:CheckIn:E] Running Loop=1
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.473511 min 
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn:E] Stopped
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn] Stopped
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn](INFO): Running loop #10
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn] Running Loop=10
2024-01-19T00:12:43.882Z,1705623163.882 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-19T00:12:43.883Z,1705623163.883 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-19T00:12:45.888Z,1705623165.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001244.00,A,3648.16378,N,12147.28646,W,1.205,186.39,190124,,,A*7E
2024-01-19T00:12:45.890Z,1705623165.890 [NAL9602](INFO): GPS fix at 20240119T001244: (36.802730, -121.788108)
2024-01-19T00:12:45.922Z,1705623165.922 [Default:CheckIn:Read_GPS] Stopped
2024-01-19T00:12:45.922Z,1705623165.922 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-19T00:12:53.324Z,1705623173.324 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240118T213454/Courier0055.lzma
2024-01-19T00:12:54.327Z,1705623174.327 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0055.lzma.bak
2024-01-19T00:12:54.327Z,1705623174.327 [DataOverHttps](INFO): SBD MOMSN=19164499
2024-01-19T00:13:10.200Z,1705623190.200 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20240118T213454/Express0056.lzma
2024-01-19T00:13:11.203Z,1705623191.203 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0056.lzma.bak
2024-01-19T00:13:11.203Z,1705623191.203 [DataOverHttps](INFO): SBD MOMSN=19164502
2024-01-19T00:13:12.696Z,1705623192.696 [Default:CheckIn:Read_Iridium] Stopped
2024-01-19T00:13:12.696Z,1705623192.696 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-19T00:13:12.696Z,1705623192.696 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-19T00:13:18.333Z,1705623198.333 [NAL9602](INFO): Not Powering down - fast GPS
2024-01-19T00:18:13.284Z,1705623493.284 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-01-19T00:18:13.284Z,1705623493.284 [Default:CheckIn:C.Wait] Stopped
2024-01-19T00:18:13.284Z,1705623493.284 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-19T00:18:13.285Z,1705623493.285 [Default:CheckIn:D] Running Loop=1
2024-01-19T00:18:13.681Z,1705623493.681 [Default:CheckIn:D] Stopped
2024-01-19T00:18:13.681Z,1705623493.681 [Default:CheckIn:E] Running Loop=1
2024-01-19T00:18:14.079Z,1705623494.079 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.976994 min 
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn:E] Stopped
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn] Stopped
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn](INFO): Running loop #11
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn] Running Loop=11
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-01-19T00:18:14.080Z,1705623494.080 [Default:CheckIn:Read_GPS] Running Loop=1
2024-01-19T00:18:16.092Z,1705623496.092 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001814.00,A,3648.17992,N,12147.26784,W,0.447,28.55,190124,,,A*41
2024-01-19T00:18:16.095Z,1705623496.095 [NAL9602](INFO): GPS fix at 20240119T001814: (36.802999, -121.787797)
2024-01-19T00:18:16.107Z,1705623496.107 [Default:CheckIn:Read_GPS] Stopped
2024-01-19T00:18:16.107Z,1705623496.107 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-01-19T00:18:23.788Z,1705623503.788 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240118T213454/Courier0058.lzma
2024-01-19T00:18:24.791Z,1705623504.791 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Courier0058.lzma.bak
2024-01-19T00:18:24.791Z,1705623504.791 [DataOverHttps](INFO): SBD MOMSN=19164506
2024-01-19T00:18:41.008Z,1705623521.008 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20240118T213454/Express0059.lzma
2024-01-19T00:18:42.011Z,1705623522.011 [DataOverHttps](INFO): Moved sent file to Logs/20240118T213454/Express0059.lzma.bak
2024-01-19T00:18:42.011Z,1705623522.011 [DataOverHttps](INFO): SBD MOMSN=19164512
2024-01-19T00:18:43.173Z,1705623523.173 [Default:CheckIn:Read_Iridium] Stopped
2024-01-19T00:18:43.173Z,1705623523.173 [Default:CheckIn:C.Wait] Running Loop=1
2024-01-19T00:18:43.173Z,1705623523.173 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-01-19T00:18:46.794Z,1705623526.794 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-01-19T00:18:46.873Z,1705623526.873 [NAL9602](ERROR): received: 
+CSQ:0

OK283, 2, 0, 0, 0

OK
2024-01-19T00:18:50.562Z,1705623530.562 [CommandExec](IMPORTANT): got command restart system
2024-01-19T00:18:52.621Z,1705623532.621 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:52.621Z,1705623532.621 [CommandExec](INFO): Uninitializing the command executive.
2024-01-19T00:18:52.621Z,1705623532.621 [CommandExec](INFO): Uninitializing the command scheduler.
2024-01-19T00:18:52.622Z,1705623532.622 [CommandExec ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:52.697Z,1705623532.697 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2024-01-19T00:18:52.697Z,1705623532.697 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2024-01-19T00:18:52.697Z,1705623532.697 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:52.698Z,1705623532.698 [NavChartDb](INFO): Join timeout helper Thread ID is 7649
2024-01-19T00:18:52.997Z,1705623532.997 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:52.997Z,1705623532.997 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.021Z,1705623533.021 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2024-01-19T00:18:53.021Z,1705623533.021 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.022Z,1705623533.022 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7650
2024-01-19T00:18:53.417Z,1705623533.417 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:53.417Z,1705623533.417 [WetLabsBB2FL](INFO): Powering down
2024-01-19T00:18:53.418Z,1705623533.418 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.430Z,1705623533.430 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2024-01-19T00:18:53.431Z,1705623533.431 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.431Z,1705623533.431 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7651
2024-01-19T00:18:53.809Z,1705623533.809 [CTD_Seabird](INFO): Powering down
2024-01-19T00:18:53.821Z,1705623533.821 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:53.821Z,1705623533.821 [CTD_Seabird](INFO): Powering down
2024-01-19T00:18:53.833Z,1705623533.833 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.846Z,1705623533.846 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2024-01-19T00:18:53.846Z,1705623533.846 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:53.847Z,1705623533.847 [Radio_Surface](INFO): Join timeout helper Thread ID is 7652
2024-01-19T00:18:54.161Z,1705623534.161 [Radio_Surface](INFO): Powering down
2024-01-19T00:18:54.162Z,1705623534.162 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.162Z,1705623534.162 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.174Z,1705623534.174 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2024-01-19T00:18:54.174Z,1705623534.174 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.175Z,1705623534.175 [Onboard](INFO): Join timeout helper Thread ID is 7653
2024-01-19T00:18:54.233Z,1705623534.233 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.233Z,1705623534.233 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.254Z,1705623534.254 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2024-01-19T00:18:54.254Z,1705623534.254 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.255Z,1705623534.255 [DataOverHttps](INFO): Join timeout helper Thread ID is 7654
2024-01-19T00:18:54.541Z,1705623534.541 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.541Z,1705623534.541 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.562Z,1705623534.562 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2024-01-19T00:18:54.562Z,1705623534.562 [logger ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.562Z,1705623534.562 [logger](INFO): Join timeout helper Thread ID is 7655
2024-01-19T00:18:54.584Z,1705623534.584 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.585Z,1705623534.585 [logger ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.590Z,1705623534.590 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2024-01-19T00:18:54.590Z,1705623534.590 [CommandLine ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.590Z,1705623534.590 [CommandLine](INFO): Join timeout helper Thread ID is 7656
2024-01-19T00:18:54.677Z,1705623534.677 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.677Z,1705623534.677 [CommandLine ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.690Z,1705623534.690 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2024-01-19T00:18:54.690Z,1705623534.690 [CommandExec ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.690Z,1705623534.690 [CommandExec](INFO): Join timeout helper Thread ID is 7657
2024-01-19T00:18:54.691Z,1705623534.691 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2024-01-19T00:18:54.691Z,1705623534.691 [controlThread ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:54.692Z,1705623534.692 [controlThread](INFO): Join timeout helper Thread ID is 7658
2024-01-19T00:18:54.857Z,1705623534.857 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2024-01-19T00:18:54.857Z,1705623534.857 [controlThread](DEBUG): Uninitializing ControlThread
2024-01-19T00:18:54.858Z,1705623534.858 [AHRS_M2](INFO): Powering down
2024-01-19T00:18:54.930Z,1705623534.930 [NAL9602](INFO): Powering down
2024-01-19T00:18:54.931Z,1705623534.931 [Sonardyne_Nano](INFO): Powering down
2024-01-19T00:18:55.051Z,1705623535.051 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2024-01-19T00:18:55.051Z,1705623535.051 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2024-01-19T00:18:55.052Z,1705623535.052 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2024-01-19T00:18:55.052Z,1705623535.052 [MissionManager](INFO): Uninitializing Mission Default
2024-01-19T00:18:55.052Z,1705623535.052 [Default] Stopped
2024-01-19T00:18:55.053Z,1705623535.053 [Default](DEBUG): Aggregate::uninitialize Default
2024-01-19T00:18:55.053Z,1705623535.053 [Default:B.GoToSurface] Stopped
2024-01-19T00:18:55.053Z,1705623535.053 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-01-19T00:18:55.053Z,1705623535.053 [Default:CheckIn] Stopped
2024-01-19T00:18:55.053Z,1705623535.053 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-01-19T00:18:55.053Z,1705623535.053 [Default:CheckIn:C.Wait] Stopped
2024-01-19T00:18:55.053Z,1705623535.053 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-01-19T00:18:55.056Z,1705623535.056 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2024-01-19T00:18:55.056Z,1705623535.056 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2024-01-19T00:18:55.057Z,1705623535.057 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2024-01-19T00:18:55.057Z,1705623535.057 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2024-01-19T00:18:55.058Z,1705623535.058 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2024-01-19T00:18:55.058Z,1705623535.058 [BuoyancyServo](INFO): Powering down
2024-01-19T00:18:55.073Z,1705623535.073 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2024-01-19T00:18:55.073Z,1705623535.073 [ElevatorServo](INFO): Powering down
2024-01-19T00:18:55.074Z,1705623535.074 [MassServo](DEBUG): Uninitialize Mass Servo.
2024-01-19T00:18:55.074Z,1705623535.074 [MassServo](INFO): Powering down
2024-01-19T00:18:55.075Z,1705623535.075 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2024-01-19T00:18:55.075Z,1705623535.075 [RudderServo](INFO): Powering down
2024-01-19T00:18:55.076Z,1705623535.076 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-01-19T00:18:55.076Z,1705623535.076 [ThrusterHE](INFO): Powering down
2024-01-19T00:18:55.077Z,1705623535.077 [SBIT](DEBUG): Uninitialize SBIT Component.
2024-01-19T00:18:55.078Z,1705623535.078 [IBIT](DEBUG): Uninitialize IBIT Component.
2024-01-19T00:18:55.078Z,1705623535.078 [CBIT](DEBUG): Uninitialize CBIT Component.
2024-01-19T00:18:55.078Z,1705623535.078 [CBIT](DEBUG): Powering off loads.
2024-01-19T00:18:55.089Z,1705623535.089 [CBIT](DEBUG): Disabling WDT.
2024-01-19T00:18:55.101Z,1705623535.101 [CBIT](DEBUG): Opening all GF detection circuits.
2024-01-19T00:18:55.102Z,1705623535.102 [controlThread ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.151Z,1705623535.151 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.154Z,1705623535.154 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.161Z,1705623535.161 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.236Z,1705623535.236 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.240Z,1705623535.240 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.285Z,1705623535.285 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-01-19T00:18:55.365Z,1705623535.365 [logger ThreadHandler](INFO): Thread cancelled.