2022-10-06T16:15:17.117Z,1665072917.117 [Supervisor](DEBUG): Initializing supervisor.
2022-10-06T16:15:17.121Z,1665072917.121 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-10-06T16:15:17.122Z,1665072917.122 [SyncHandler](INFO): Protected caller Thread ID is 6182
2022-10-06T16:15:17.122Z,1665072917.122 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-10-06T16:15:17.123Z,1665072917.123 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-10-06T16:15:17.124Z,1665072917.124 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6183
2022-10-06T16:15:17.128Z,1665072917.128 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-10-06T16:15:17.145Z,1665072917.145 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-10-06T16:15:17.146Z,1665072917.146 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-10-06T16:15:17.146Z,1665072917.146 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6184
2022-10-06T16:15:17.150Z,1665072917.150 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-10-06T16:15:17.151Z,1665072917.151 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-10-06T16:15:17.152Z,1665072917.152 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6185
2022-10-06T16:15:17.154Z,1665072917.154 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-10-06T16:15:17.155Z,1665072917.155 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-10-06T16:15:17.155Z,1665072917.155 [logger ThreadHandler](INFO): Protected caller Thread ID is 6186
2022-10-06T16:15:17.159Z,1665072917.159 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-10-06T16:15:17.159Z,1665072917.159 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-10-06T16:15:17.161Z,1665072917.161 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-10-06T16:15:17.403Z,1665072917.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-10-06T16:15:17.404Z,1665072917.404 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-10-06T16:15:17.482Z,1665072917.482 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-10-06T16:15:17.929Z,1665072917.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-10-06T16:15:17.930Z,1665072917.930 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-10-06T16:15:18.233Z,1665072918.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-10-06T16:15:18.234Z,1665072918.234 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-10-06T16:15:18.327Z,1665072918.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-10-06T16:15:18.327Z,1665072918.327 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-10-06T16:15:18.676Z,1665072918.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-10-06T16:15:18.676Z,1665072918.676 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-10-06T16:15:18.870Z,1665072918.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-10-06T16:15:18.870Z,1665072918.870 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-10-06T16:15:19.310Z,1665072919.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-10-06T16:15:19.310Z,1665072919.310 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-10-06T16:15:19.440Z,1665072919.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-10-06T16:15:19.441Z,1665072919.441 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-10-06T16:15:19.517Z,1665072919.517 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-10-06T16:15:20.188Z,1665072920.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-10-06T16:15:20.189Z,1665072920.189 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-10-06T16:15:20.534Z,1665072920.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-10-06T16:15:20.535Z,1665072920.535 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-10-06T16:15:20.710Z,1665072920.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-10-06T16:15:20.710Z,1665072920.710 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-10-06T16:15:20.817Z,1665072920.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-10-06T16:15:20.818Z,1665072920.818 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-10-06T16:15:21.048Z,1665072921.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-10-06T16:15:21.048Z,1665072921.048 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-10-06T16:15:21.527Z,1665072921.527 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-10-06T16:15:21.529Z,1665072921.529 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2022-10-06T16:15:21.530Z,1665072921.530 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2022-10-06T16:15:21.791Z,1665072921.791 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2022-10-06T16:15:21.924Z,1665072921.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2022-10-06T16:15:22.106Z,1665072922.106 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2022-10-06T16:15:22.188Z,1665072922.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2022-10-06T16:15:22.282Z,1665072922.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2022-10-06T16:15:22.382Z,1665072922.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2022-10-06T16:15:22.560Z,1665072922.560 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2022-10-06T16:15:22.635Z,1665072922.635 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2022-10-06T16:15:22.774Z,1665072922.774 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2022-10-06T16:15:22.904Z,1665072922.904 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2022-10-06T16:15:23.014Z,1665072923.014 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2022-10-06T16:15:23.268Z,1665072923.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-10-06T16:15:23.269Z,1665072923.269 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-10-06T16:15:23.282Z,1665072923.282 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-10-06T16:15:23.333Z,1665072923.333 [VerticalControl](DEBUG): Construct VerticalControl.
2022-10-06T16:15:23.392Z,1665072923.392 [VerticalControl] Loaded
2022-10-06T16:15:23.393Z,1665072923.393 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-10-06T16:15:23.395Z,1665072923.395 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-10-06T16:15:23.435Z,1665072923.435 [HorizontalControl] Loaded
2022-10-06T16:15:23.436Z,1665072923.436 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-10-06T16:15:23.438Z,1665072923.438 [SpeedControl](DEBUG): Construct SpeedControl.
2022-10-06T16:15:23.441Z,1665072923.441 [SpeedControl] Loaded
2022-10-06T16:15:23.441Z,1665072923.441 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-10-06T16:15:23.444Z,1665072923.444 [LoopControl](DEBUG): Construct LoopControl.
2022-10-06T16:15:23.444Z,1665072923.444 [LoopControl] Loaded
2022-10-06T16:15:23.445Z,1665072923.445 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-10-06T16:15:23.445Z,1665072923.445 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-10-06T16:15:23.446Z,1665072923.446 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-10-06T16:15:23.456Z,1665072923.456 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-10-06T16:15:23.456Z,1665072923.456 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-10-06T16:15:23.606Z,1665072923.606 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-10-06T16:15:23.607Z,1665072923.607 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-10-06T16:15:23.727Z,1665072923.727 [BuoyancyServo] Loaded
2022-10-06T16:15:23.727Z,1665072923.727 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-10-06T16:15:23.747Z,1665072923.747 [ElevatorServo] Loaded
2022-10-06T16:15:23.747Z,1665072923.747 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-10-06T16:15:23.765Z,1665072923.765 [MassServo] Loaded
2022-10-06T16:15:23.766Z,1665072923.766 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-10-06T16:15:23.784Z,1665072923.784 [RudderServo] Loaded
2022-10-06T16:15:23.784Z,1665072923.784 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-10-06T16:15:23.801Z,1665072923.801 [ThrusterServo] Loaded
2022-10-06T16:15:23.801Z,1665072923.801 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-10-06T16:15:23.802Z,1665072923.802 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-10-06T16:15:23.802Z,1665072923.802 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-10-06T16:15:23.913Z,1665072923.913 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-10-06T16:15:23.913Z,1665072923.913 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-10-06T16:15:23.927Z,1665072923.927 [NavChart] Loaded
2022-10-06T16:15:23.927Z,1665072923.927 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-10-06T16:15:23.933Z,1665072923.933 [UniversalFixResidualReporter] Loaded
2022-10-06T16:15:23.933Z,1665072923.933 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-10-06T16:15:23.933Z,1665072923.933 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-10-06T16:15:23.934Z,1665072923.934 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-10-06T16:15:23.989Z,1665072923.989 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-10-06T16:15:23.990Z,1665072923.990 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-10-06T16:15:24.375Z,1665072924.375 [AHRS_M2] Loaded
2022-10-06T16:15:24.376Z,1665072924.376 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-10-06T16:15:25.177Z,1665072925.177 [BPC1] Loaded
2022-10-06T16:15:25.177Z,1665072925.177 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-10-06T16:15:25.315Z,1665072925.315 [DataOverHttps] Loaded
2022-10-06T16:15:25.316Z,1665072925.316 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-10-06T16:15:25.325Z,1665072925.325 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408F04E0
2022-10-06T16:15:25.326Z,1665072925.326 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6272
2022-10-06T16:15:25.347Z,1665072925.347 [Depth_Keller] Loaded
2022-10-06T16:15:25.347Z,1665072925.347 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-10-06T16:15:25.352Z,1665072925.352 [DropWeight] Loaded
2022-10-06T16:15:25.353Z,1665072925.353 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-10-06T16:15:25.418Z,1665072925.418 [NAL9602] Loaded
2022-10-06T16:15:25.419Z,1665072925.419 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-10-06T16:15:25.448Z,1665072925.448 [Onboard] Loaded
2022-10-06T16:15:25.448Z,1665072925.448 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-10-06T16:15:25.449Z,1665072925.449 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409204E0
2022-10-06T16:15:25.450Z,1665072925.450 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6273
2022-10-06T16:15:25.463Z,1665072925.463 [Power24vConverter] Loaded
2022-10-06T16:15:25.463Z,1665072925.463 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-10-06T16:15:25.476Z,1665072925.476 [Radio_Surface] Loaded
2022-10-06T16:15:25.476Z,1665072925.476 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-10-06T16:15:25.477Z,1665072925.477 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409504E0
2022-10-06T16:15:25.477Z,1665072925.477 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6274
2022-10-06T16:15:25.478Z,1665072925.478 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-10-06T16:15:25.479Z,1665072925.479 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-10-06T16:15:25.528Z,1665072925.528 [DepthRateCalculator] Loaded
2022-10-06T16:15:25.528Z,1665072925.528 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-10-06T16:15:25.533Z,1665072925.533 [PitchRateCalculator] Loaded
2022-10-06T16:15:25.533Z,1665072925.533 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-10-06T16:15:25.542Z,1665072925.542 [SpeedCalculator] Loaded
2022-10-06T16:15:25.542Z,1665072925.542 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-10-06T16:15:25.546Z,1665072925.546 [YawRateCalculator] Loaded
2022-10-06T16:15:25.547Z,1665072925.547 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-10-06T16:15:25.565Z,1665072925.565 [ElevatorOffsetCalculator] Loaded
2022-10-06T16:15:25.566Z,1665072925.566 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-10-06T16:15:25.566Z,1665072925.566 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-10-06T16:15:25.567Z,1665072925.567 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-10-06T16:15:25.695Z,1665072925.695 [CANONSampler] Loaded
2022-10-06T16:15:25.695Z,1665072925.695 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2022-10-06T16:15:25.753Z,1665072925.753 [CTD_Seabird] Loaded
2022-10-06T16:15:25.753Z,1665072925.753 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-10-06T16:15:25.754Z,1665072925.754 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A094E0
2022-10-06T16:15:25.754Z,1665072925.754 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6275
2022-10-06T16:15:25.774Z,1665072925.774 [PAR_Licor] Loaded
2022-10-06T16:15:25.775Z,1665072925.775 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-10-06T16:15:25.805Z,1665072925.805 [WetLabsBB2FL] Loaded
2022-10-06T16:15:25.805Z,1665072925.805 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-10-06T16:15:25.806Z,1665072925.806 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A394E0
2022-10-06T16:15:25.807Z,1665072925.807 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6276
2022-10-06T16:15:25.807Z,1665072925.807 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-10-06T16:15:25.808Z,1665072925.808 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-10-06T16:15:25.835Z,1665072925.835 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-10-06T16:15:25.835Z,1665072925.835 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-10-06T16:15:26.136Z,1665072926.136 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-10-06T16:15:26.137Z,1665072926.137 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-10-06T16:15:26.489Z,1665072926.489 [SBIT](DEBUG): Construct Startup Built In Test.
2022-10-06T16:15:26.498Z,1665072926.498 [SBIT] Loaded
2022-10-06T16:15:26.498Z,1665072926.498 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-10-06T16:15:26.501Z,1665072926.501 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-10-06T16:15:26.513Z,1665072926.513 [IBIT] Loaded
2022-10-06T16:15:26.514Z,1665072926.514 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-10-06T16:15:26.520Z,1665072926.520 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-10-06T16:15:26.719Z,1665072926.719 [CBIT] Loaded
2022-10-06T16:15:26.719Z,1665072926.719 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-10-06T16:15:26.720Z,1665072926.720 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-10-06T16:15:26.720Z,1665072926.720 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-10-06T16:15:26.813Z,1665072926.813 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-10-06T16:15:26.819Z,1665072926.819 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-10-06T16:15:26.822Z,1665072926.822 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-10-06T16:15:26.833Z,1665072926.833 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-10-06T16:15:26.834Z,1665072926.834 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-10-06T16:15:26.834Z,1665072926.834 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6277
2022-10-06T16:15:26.839Z,1665072926.839 [Supervisor](INFO): Main Thread ID is 6181
2022-10-06T16:15:26.839Z,1665072926.839 [Supervisor](DEBUG): Running supervisor.
2022-10-06T16:15:26.839Z,1665072926.839 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6278
2022-10-06T16:15:26.840Z,1665072926.840 [CommandExec](INFO): Initializing the command executive.
2022-10-06T16:15:26.842Z,1665072926.842 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6279
2022-10-06T16:15:26.844Z,1665072926.844 [controlThread ThreadHandler](INFO): Handler Thread ID is 6280
2022-10-06T16:15:26.844Z,1665072926.844 [controlThread](DEBUG): Initializing ControlThread
2022-10-06T16:15:26.845Z,1665072926.845 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-10-06T16:15:26.847Z,1665072926.847 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-10-06T16:15:26.848Z,1665072926.848 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-10-06T16:15:26.848Z,1665072926.848 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-10-06T16:15:26.850Z,1665072926.850 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-10-06T16:15:26.850Z,1665072926.850 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-10-06T16:15:26.855Z,1665072926.855 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-10-06T16:15:26.855Z,1665072926.855 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-10-06T16:15:26.856Z,1665072926.856 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-10-06T16:15:26.856Z,1665072926.856 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-10-06T16:15:26.856Z,1665072926.856 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-10-06T16:15:26.862Z,1665072926.862 [SBIT](INFO): Initialize SBIT Component.
2022-10-06T16:15:26.862Z,1665072926.862 [SBIT](IMPORTANT): git: 2022-09-08
2022-10-06T16:15:26.862Z,1665072926.862 [SBIT](INFO): git hash: 1923f3a7c5c14ef35d1c7a327e27a495a1a7ac01
2022-10-06T16:15:26.862Z,1665072926.862 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-10-06T16:15:26.864Z,1665072926.864 [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
2022-10-06T16:15:26.865Z,1665072926.865 [SBIT](INFO): Beginning SBIT in 71.000000 seconds.
2022-10-06T16:15:26.865Z,1665072926.865 [IBIT](INFO): Initialize IBIT Component.
2022-10-06T16:15:26.866Z,1665072926.866 [CBIT](DEBUG): Initialize CBIT Component.
2022-10-06T16:15:26.867Z,1665072926.867 [logger ThreadHandler](INFO): Handler Thread ID is 6281
2022-10-06T16:15:26.877Z,1665072926.877 [CBIT](DEBUG): Initialized mux pins.
2022-10-06T16:15:26.877Z,1665072926.877 [CBIT](DEBUG): Initializing the watchdog timer.
2022-10-06T16:15:26.886Z,1665072926.886 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6282
2022-10-06T16:15:26.887Z,1665072926.887 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-10-06T16:15:26.898Z,1665072926.898 [Onboard ThreadHandler](INFO): Handler Thread ID is 6283
2022-10-06T16:15:26.902Z,1665072926.902 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-10-06T16:15:26.902Z,1665072926.902 [CBIT](DEBUG): Initializing heartbeat.
2022-10-06T16:15:26.918Z,1665072926.918 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6284
2022-10-06T16:15:26.934Z,1665072926.934 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6285
2022-10-06T16:15:26.934Z,1665072926.934 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-10-06T16:15:26.939Z,1665072926.939 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6287
2022-10-06T16:15:26.942Z,1665072926.942 [WetLabsBB2FL](INFO): Powering up
2022-10-06T16:15:26.943Z,1665072926.943 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6289
2022-10-06T16:15:26.946Z,1665072926.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-10-06T16:15:26.946Z,1665072926.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-10-06T16:15:26.947Z,1665072926.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-10-06T16:15:26.973Z,1665072926.973 [CBIT](DEBUG): Deactivating GF circuits.
2022-10-06T16:15:26.973Z,1665072926.973 [CBIT](DEBUG): Deactivating emergency mode.
2022-10-06T16:15:27.009Z,1665072927.009 [CBIT](DEBUG): Backplane powered.
2022-10-06T16:15:27.010Z,1665072927.010 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-10-06T16:15:27.023Z,1665072927.023 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-06T16:15:27.047Z,1665072927.047 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2022-10-06T16:15:27.047Z,1665072927.047 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-10-06T16:15:27.121Z,1665072927.121 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-10-06T16:15:27.122Z,1665072927.122 [Default:A.Wait](DEBUG): Construct Wait.
2022-10-06T16:15:27.124Z,1665072927.124 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-06T16:15:27.168Z,1665072927.168 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-10-06T16:15:27.170Z,1665072927.170 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-10-06T16:15:27.196Z,1665072927.196 [Default:E.Execute](DEBUG): Construct Execute.
2022-10-06T16:15:27.199Z,1665072927.199 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-10-06T16:15:27.213Z,1665072927.213 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-10-06T16:15:27.227Z,1665072927.227 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-10-06T16:15:27.296Z,1665072927.296 [Power24vConverter](INFO): Powering up.
2022-10-06T16:15:27.296Z,1665072927.296 [CANONSampler](INFO): Powering down
2022-10-06T16:15:27.321Z,1665072927.321 [Radio_Surface](INFO): Powering up
2022-10-06T16:15:27.392Z,1665072927.392 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:27.393Z,1665072927.393 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-10-06T16:15:27.395Z,1665072927.395 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:27.401Z,1665072927.401 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-10-06T16:15:27.402Z,1665072927.402 [MassServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:27.409Z,1665072927.409 [MassServo](DEBUG): Initializing MassServo.
2022-10-06T16:15:27.410Z,1665072927.410 [RudderServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:27.421Z,1665072927.421 [RudderServo](DEBUG): Initializing RudderServo.
2022-10-06T16:15:27.422Z,1665072927.422 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:27.429Z,1665072927.429 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-10-06T16:15:27.661Z,1665072927.661 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-10-06T16:15:27.661Z,1665072927.661 [DropWeight] Hardware Fault, FailCount= 1
2022-10-06T16:15:27.661Z,1665072927.661 [DropWeight](ERROR): Hardware Fault
2022-10-06T16:15:27.701Z,1665072927.701 [CommandExec](FAULT): Scheduling is paused
2022-10-06T16:15:27.709Z,1665072927.709 [CBIT](INFO): Critical error at 20221006T161527
2022-10-06T16:15:27.710Z,1665072927.710 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-10-06T16:15:27.712Z,1665072927.712 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-10-06T16:15:27.712Z,1665072927.712 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-10-06T16:15:28.353Z,1665072928.353 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-10-06T16:15:28.353Z,1665072928.353 [RudderServo](FAULT): Rudder failed to initialize
2022-10-06T16:15:28.353Z,1665072928.353 [RudderServo] Communications Fault, FailCount= 1
2022-10-06T16:15:28.353Z,1665072928.353 [RudderServo](ERROR): Communications Fault
2022-10-06T16:15:28.451Z,1665072928.451 [CBIT](INFO): Critical error at 20221006T161527
2022-10-06T16:15:28.454Z,1665072928.454 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-10-06T16:15:28.614Z,1665072928.614 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-10-06T16:15:28.614Z,1665072928.614 [RudderServo](INFO): Powering down
2022-10-06T16:15:29.057Z,1665072929.057 [WetLabsBB2FL](INFO): Powering down
2022-10-06T16:15:29.320Z,1665072929.320 [RudderServo](DEBUG): Initializing EZServoServo.
2022-10-06T16:15:29.438Z,1665072929.438 [RudderServo](DEBUG): Initializing RudderServo.
2022-10-06T16:15:29.442Z,1665072929.442 [CBIT](INFO): Clearing failed state for component RudderServo
2022-10-06T16:15:29.442Z,1665072929.442 [RudderServo] No Fault, FailCount= 1
2022-10-06T16:15:40.967Z,1665072940.967 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004701
2022-10-06T16:15:55.535Z,1665072955.535 [NAL9602](INFO): Powering up NAL9602
2022-10-06T16:16:06.443Z,1665072966.443 [NAL9602](INFO): NAL9602 initialized
2022-10-06T16:16:31.002Z,1665072991.002 [CommandExec](IMPORTANT): got command show variable par
2022-10-06T16:16:31.038Z,1665072991.038 [CommandExec](IMPORTANT): PAR_Licor.loadControl (none)
2022-10-06T16:16:31.038Z,1665072991.038 [CommandExec](IMPORTANT): PAR_Licor.ad (none)
2022-10-06T16:16:31.039Z,1665072991.039 [CommandExec](IMPORTANT): PAR_Licor.adRes (bit)
2022-10-06T16:16:31.039Z,1665072991.039 [CommandExec](IMPORTANT): PAR_Licor.adTimeout (millisecond)
2022-10-06T16:16:31.039Z,1665072991.039 [CommandExec](IMPORTANT): PAR_Licor.adVref (volt)
2022-10-06T16:16:31.125Z,1665072991.125 [CommandExec](IMPORTANT): PAR_Licor.loadAtStartup (bool)
2022-10-06T16:16:31.126Z,1665072991.126 [CommandExec](IMPORTANT): PAR_Licor.simulateHardware (bool)
2022-10-06T16:16:31.126Z,1665072991.126 [CommandExec](IMPORTANT): PAR_Licor.adcCal (microampere_per_count)
2022-10-06T16:16:31.126Z,1665072991.126 [CommandExec](IMPORTANT): PAR_Licor.darkCount (count)
2022-10-06T16:16:31.127Z,1665072991.127 [CommandExec](IMPORTANT): PAR_Licor.maxBound (micromole_per_second_per_square_meter)
2022-10-06T16:16:31.127Z,1665072991.127 [CommandExec](IMPORTANT): PAR_Licor.maxValidPitch (degree)
2022-10-06T16:16:31.127Z,1665072991.127 [CommandExec](IMPORTANT): PAR_Licor.minBound (micromole_per_second_per_square_meter)
2022-10-06T16:16:31.128Z,1665072991.128 [CommandExec](IMPORTANT): PAR_Licor.minValidPitch (degree)
2022-10-06T16:16:31.128Z,1665072991.128 [CommandExec](IMPORTANT): PAR_Licor.multiplier (micromole_per_second_per_square_meter_per_microampere)
2022-10-06T16:16:31.129Z,1665072991.129 [CommandExec](IMPORTANT): PAR_Licor.parCal (none)
2022-10-06T16:16:31.142Z,1665072991.142 [CommandExec](IMPORTANT): PAR_Licor.serial (none)
2022-10-06T16:16:31.306Z,1665072991.306 [CommandExec](IMPORTANT): PAR_Licor.enableBroadcast (bool)
2022-10-06T16:16:31.306Z,1665072991.306 [CommandExec](IMPORTANT): PAR_Licor.component_voltage (volt)
2022-10-06T16:16:31.307Z,1665072991.307 [CommandExec](IMPORTANT): PAR_Licor.component_avgVoltage (volt)
2022-10-06T16:16:31.307Z,1665072991.307 [CommandExec](IMPORTANT): PAR_Licor.component_current (milliampere)
2022-10-06T16:16:31.307Z,1665072991.307 [CommandExec](IMPORTANT): PAR_Licor.component_avgCurrent (milliampere)
2022-10-06T16:16:31.308Z,1665072991.308 [CommandExec](IMPORTANT): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water (micromole_per_second_per_square_meter)
2022-10-06T16:16:31.308Z,1665072991.308 [CommandExec](IMPORTANT): PAR_Licor.adcCount (count)
2022-10-06T16:16:38.375Z,1665072998.375 [SBIT](IMPORTANT): Beginning Startup BIT
2022-10-06T16:16:38.379Z,1665072998.379 [CBIT](IMPORTANT): Beginning ground fault scan
2022-10-06T16:16:49.298Z,1665073009.298 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.001414
CHAN A1 (24V): 0.000718
CHAN A2 (12V): -0.002356
CHAN A3 (5V): -0.001404
CHAN B0 (3.3V): 0.000055
CHAN B1 (3.15aV): -0.000513
CHAN B2 (3.15bV): -0.000252
CHAN B3 (GND): 0.000168
OPEN: -0.000374
Full Scale: +/- 1 mA
2022-10-06T16:17:23.041Z,1665073043.041 [CommandExec](IMPORTANT): got command report mod PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water
2022-10-06T16:17:23.392Z,1665073043.392 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.790465 umol/s/m2
2022-10-06T16:17:23.847Z,1665073043.847 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.776052 umol/s/m2
2022-10-06T16:17:24.120Z,1665073044.120 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.793347 umol/s/m2
2022-10-06T16:17:24.536Z,1665073044.536 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.778934 umol/s/m2
2022-10-06T16:17:24.927Z,1665073044.927 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.807760 umol/s/m2
2022-10-06T16:17:25.328Z,1665073045.328 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.755873 umol/s/m2
2022-10-06T16:17:25.743Z,1665073045.743 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.813525 umol/s/m2
2022-10-06T16:17:26.151Z,1665073046.151 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.807760 umol/s/m2
2022-10-06T16:17:26.535Z,1665073046.535 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.758756 umol/s/m2
2022-10-06T16:17:26.943Z,1665073046.943 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.859647 umol/s/m2
2022-10-06T16:17:27.355Z,1665073047.355 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.761638 umol/s/m2
2022-10-06T16:17:27.867Z,1665073047.867 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.755873 umol/s/m2
2022-10-06T16:17:28.207Z,1665073048.207 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.758756 umol/s/m2
2022-10-06T16:17:28.587Z,1665073048.587 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.770286 umol/s/m2
2022-10-06T16:17:28.975Z,1665073048.975 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.755873 umol/s/m2
2022-10-06T16:17:29.367Z,1665073049.367 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.793347 umol/s/m2
2022-10-06T16:17:29.759Z,1665073049.759 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.611742 umol/s/m2
2022-10-06T16:17:30.143Z,1665073050.143 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.355189 umol/s/m2
2022-10-06T16:17:30.575Z,1665073050.575 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.381132 umol/s/m2
2022-10-06T16:17:30.971Z,1665073050.971 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.611742 umol/s/m2
2022-10-06T16:17:31.367Z,1665073051.367 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 10.584990 umol/s/m2
2022-10-06T16:17:31.791Z,1665073051.791 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.539677 umol/s/m2
2022-10-06T16:17:32.170Z,1665073052.170 [SBIT](IMPORTANT): SBIT PASSED
2022-10-06T16:17:32.170Z,1665073052.170 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-10-06T16:17:32.171Z,1665073052.171 [SBIT](IMPORTANT): AHRS_M2.readAccelerations=0 bool;

2022-10-06T16:17:32.171Z,1665073052.171 [SBIT](IMPORTANT): AHRS_M2.readAngularVelocities=0 bool;

2022-10-06T16:17:32.171Z,1665073052.171 [SBIT](IMPORTANT): AHRS_M2.readMagnetics=0 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=3 count;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): CANONSampler.sampleTimeout=10 minute;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2022-10-06T16:17:32.172Z,1665073052.172 [SBIT](IMPORTANT): Express linearApproximation NAL9602.sigQuality 1.000000 count;

2022-10-06T16:17:32.173Z,1665073052.173 [SBIT](IMPORTANT): Express linearApproximation ThrusterServo.component_avgCurrent 10.000000 milliampere;

2022-10-06T16:17:32.173Z,1665073052.173 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=297 cubic_centimeter;

2022-10-06T16:17:32.173Z,1665073052.173 [SBIT](IMPORTANT): VerticalControl.massDefault=-1.3 centimeter;

2022-10-06T16:17:32.178Z,1665073052.178 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 12.412572 umol/s/m2
2022-10-06T16:17:32.528Z,1665073052.528 [MissionManager](IMPORTANT): Started mission Startup
2022-10-06T16:17:32.528Z,1665073052.528 [Startup] Running Loop=1
2022-10-06T16:17:32.528Z,1665073052.528 [Startup](DEBUG): Aggregate::initialize Startup
2022-10-06T16:17:32.528Z,1665073052.528 [Startup:A.GoToSurface] Running Loop=1
2022-10-06T16:17:32.528Z,1665073052.528 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-06T16:17:32.529Z,1665073052.529 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-06T16:17:32.534Z,1665073052.534 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-06T16:17:32.534Z,1665073052.534 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-06T16:17:32.534Z,1665073052.534 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-06T16:17:32.535Z,1665073052.535 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-06T16:17:32.536Z,1665073052.536 [Startup:StartupSatComms] Running Loop=1
2022-10-06T16:17:32.536Z,1665073052.536 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-10-06T16:17:32.536Z,1665073052.536 [Startup:StartupSatComms:A] Running Loop=1
2022-10-06T16:17:32.607Z,1665073052.607 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 11.126923 umol/s/m2
2022-10-06T16:17:32.951Z,1665073052.951 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-10-06T16:17:33.031Z,1665073053.031 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 3.796413 umol/s/m2
2022-10-06T16:17:33.395Z,1665073053.395 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.198901 umol/s/m2
2022-10-06T16:17:33.915Z,1665073053.915 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.230610 umol/s/m2
2022-10-06T16:17:34.239Z,1665073054.239 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.239258 umol/s/m2
2022-10-06T16:17:34.627Z,1665073054.627 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.198901 umol/s/m2
2022-10-06T16:17:35.012Z,1665073055.012 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.230610 umol/s/m2
2022-10-06T16:17:35.403Z,1665073055.403 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.207549 umol/s/m2
2022-10-06T16:17:35.815Z,1665073055.815 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.204666 umol/s/m2
2022-10-06T16:17:36.203Z,1665073056.203 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.233492 umol/s/m2
2022-10-06T16:17:36.611Z,1665073056.611 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.092244 umol/s/m2
2022-10-06T16:17:37.019Z,1665073057.019 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 8.742993 umol/s/m2
2022-10-06T16:17:37.420Z,1665073057.420 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 8.154938 umol/s/m2
2022-10-06T16:17:37.835Z,1665073057.835 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 8.639219 umol/s/m2
2022-10-06T16:17:38.259Z,1665073058.259 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 11.049090 umol/s/m2
2022-10-06T16:17:38.656Z,1665073058.656 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 10.316904 umol/s/m2
2022-10-06T16:17:39.063Z,1665073059.063 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 12.132957 umol/s/m2
2022-10-06T16:17:39.463Z,1665073059.463 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.623272 umol/s/m2
2022-10-06T16:17:39.904Z,1665073059.904 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.418607 umol/s/m2
2022-10-06T16:17:40.196Z,1665073060.196 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.303302 umol/s/m2
2022-10-06T16:17:40.607Z,1665073060.607 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.683808 umol/s/m2
2022-10-06T16:17:41.022Z,1665073061.022 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.747226 umol/s/m2
2022-10-06T16:17:41.463Z,1665073061.463 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.767404 umol/s/m2
2022-10-06T16:17:41.834Z,1665073061.834 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.735695 umol/s/m2
2022-10-06T16:17:42.230Z,1665073062.230 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.773170 umol/s/m2
2022-10-06T16:17:42.637Z,1665073062.637 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.796230 umol/s/m2
2022-10-06T16:17:43.029Z,1665073063.029 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.750109 umol/s/m2
2022-10-06T16:17:43.439Z,1665073063.439 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 13.778934 umol/s/m2
2022-10-06T16:17:43.718Z,1665073063.718 [CommandExec](IMPORTANT): got command report clear
2022-10-06T16:18:27.126Z,1665073107.126 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-10-06T16:18:27.126Z,1665073107.126 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:18:27.137Z,1665073107.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:18:27.496Z,1665073107.496 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:18:27.496Z,1665073107.496 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-10-06T16:18:32.708Z,1665073112.708 [Startup:StartupSatComms:A](INFO): Timed out from 2022-10-06T16:17:32.5Z
2022-10-06T16:18:32.708Z,1665073112.708 [Startup:StartupSatComms:A] Stopped
2022-10-06T16:18:32.708Z,1665073112.708 [Startup:StartupSatComms:B] Running Loop=1
2022-10-06T16:18:33.116Z,1665073113.116 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-06T16:18:34.297Z,1665073114.297 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20221006T155031/Courier0007.lzma
2022-10-06T16:18:35.251Z,1665073115.251 [DataOverHttps](INFO): Moved sent file to Logs/20221006T155031/Courier0007.lzma.bak
2022-10-06T16:18:35.251Z,1665073115.251 [DataOverHttps](INFO): SBD MOMSN=17235182
2022-10-06T16:18:51.425Z,1665073131.425 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20221006T161517/Courier0000.lzma
2022-10-06T16:18:52.427Z,1665073132.427 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0000.lzma.bak
2022-10-06T16:18:52.427Z,1665073132.427 [DataOverHttps](INFO): SBD MOMSN=17235185
2022-10-06T16:19:07.882Z,1665073147.882 [DataOverHttps](INFO): Sending 336 bytes from file Logs/20221006T155031/Express0008.lzma
2022-10-06T16:19:08.883Z,1665073148.883 [DataOverHttps](INFO): Moved sent file to Logs/20221006T155031/Express0008.lzma.bak
2022-10-06T16:19:08.884Z,1665073148.884 [DataOverHttps](INFO): SBD MOMSN=17235190
2022-10-06T16:19:24.927Z,1665073164.927 [DataOverHttps](INFO): Sending 1447 bytes from file Logs/20221006T161517/Express0001.lzma
2022-10-06T16:19:25.927Z,1665073165.927 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0001.lzma.bak
2022-10-06T16:19:25.927Z,1665073165.927 [DataOverHttps](INFO): SBD MOMSN=17235202
2022-10-06T16:19:27.351Z,1665073167.351 [Startup:StartupSatComms:B] Stopped
2022-10-06T16:19:27.352Z,1665073167.352 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-10-06T16:19:27.352Z,1665073167.352 [Startup:StartupSatComms] Stopped
2022-10-06T16:19:27.352Z,1665073167.352 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-10-06T16:19:27.353Z,1665073167.353 [Startup](INFO): Completed Startup
2022-10-06T16:19:27.353Z,1665073167.353 [MissionManager](INFO): Startup is completed.
2022-10-06T16:19:27.353Z,1665073167.353 [MissionManager](INFO): Uninitializing Mission Startup
2022-10-06T16:19:27.353Z,1665073167.353 [Startup] Stopped
2022-10-06T16:19:27.353Z,1665073167.353 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-10-06T16:19:27.353Z,1665073167.353 [Startup:A.GoToSurface] Stopped
2022-10-06T16:19:27.353Z,1665073167.353 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-06T16:19:27.767Z,1665073167.767 [MissionManager](IMPORTANT): Started mission Default
2022-10-06T16:19:27.768Z,1665073167.768 [Default] Running Loop=1
2022-10-06T16:19:27.768Z,1665073167.768 [Default](DEBUG): Aggregate::initialize Default
2022-10-06T16:19:27.768Z,1665073167.768 [Default:B.GoToSurface] Running Loop=1
2022-10-06T16:19:27.768Z,1665073167.768 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-06T16:19:27.768Z,1665073167.768 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-06T16:19:27.768Z,1665073167.768 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-06T16:19:27.769Z,1665073167.769 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-06T16:19:27.769Z,1665073167.769 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-06T16:19:27.770Z,1665073167.770 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-06T16:19:27.770Z,1665073167.770 [Default:A.Wait] Running Loop=1
2022-10-06T16:19:27.770Z,1665073167.770 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:19:41.108Z,1665073181.108 [Default:A.Wait](INFO): Done Waiting.
2022-10-06T16:19:41.108Z,1665073181.108 [Default:A.Wait] Stopped
2022-10-06T16:19:41.108Z,1665073181.108 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:19:41.520Z,1665073181.520 [Default:CheckIn] Running Loop=1
2022-10-06T16:19:41.520Z,1665073181.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T16:19:41.520Z,1665073181.520 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T16:19:41.931Z,1665073181.931 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-10-06T16:20:23.509Z,1665073223.509 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:20:38.862Z,1665073238.862 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:20:54.214Z,1665073254.214 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:21:09.162Z,1665073269.162 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:21:09.991Z,1665073269.991 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T16:21:24.110Z,1665073284.110 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:21:28.184Z,1665073288.184 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-10-06T16:21:28.184Z,1665073288.184 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:21:28.195Z,1665073288.195 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:21:28.608Z,1665073288.608 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:21:28.608Z,1665073288.608 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-10-06T16:21:39.477Z,1665073299.477 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:21:54.830Z,1665073314.830 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:22:09.374Z,1665073329.374 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:22:24.322Z,1665073344.322 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:22:38.466Z,1665073358.466 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2022-10-06T16:24:00.305Z,1665073440.305 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:24:29.189Z,1665073469.189 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-10-06T16:24:29.189Z,1665073469.189 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:24:29.200Z,1665073469.200 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:24:29.598Z,1665073469.598 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:24:29.598Z,1665073469.598 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-10-06T16:24:31.429Z,1665073471.429 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:24:41.703Z,1665073481.703 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-06T16:19:41.5Z
2022-10-06T16:24:41.703Z,1665073481.703 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T16:24:41.703Z,1665073481.703 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T16:24:42.125Z,1665073482.125 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-06T16:25:02.553Z,1665073502.553 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:25:28.162Z,1665073528.162 [Power24vConverter](INFO): Powering down.
2022-10-06T16:25:33.677Z,1665073533.677 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:26:04.802Z,1665073564.802 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:26:07.814Z,1665073567.814 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.727539
2022-10-06T16:26:08.143Z,1665073568.143 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-06T16:26:08.143Z,1665073568.143 [NAL9602] Data Fault, FailCount= 1
2022-10-06T16:26:08.143Z,1665073568.143 [NAL9602](ERROR): Data Fault
2022-10-06T16:26:08.165Z,1665073568.165 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-06T16:26:08.550Z,1665073568.550 [NAL9602](INFO): Powering down
2022-10-06T16:26:09.375Z,1665073569.375 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-06T16:26:09.375Z,1665073569.375 [NAL9602] No Fault, FailCount= 1
2022-10-06T16:26:38.856Z,1665073598.856 [NAL9602](INFO): Powering up NAL9602
2022-10-06T16:26:38.937Z,1665073598.937 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:26:49.759Z,1665073609.759 [NAL9602](INFO): NAL9602 initialized
2022-10-06T16:27:10.061Z,1665073630.061 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:27:30.255Z,1665073650.255 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-10-06T16:27:30.255Z,1665073650.255 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:27:30.266Z,1665073650.266 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:27:30.587Z,1665073650.587 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:27:30.587Z,1665073650.587 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-10-06T16:27:41.186Z,1665073661.186 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:28:12.309Z,1665073692.309 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:28:43.433Z,1665073723.433 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:29:14.561Z,1665073754.561 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:29:41.486Z,1665073781.486 [CommandExec](IMPORTANT): got command strobe off
2022-10-06T16:29:41.487Z,1665073781.487 [CommandExec](IMPORTANT): Deactivating strobe
2022-10-06T16:29:45.698Z,1665073785.698 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:29:51.145Z,1665073791.145 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:29:54.010Z,1665073794.010 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003375
2022-10-06T16:29:58.013Z,1665073798.013 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:30:01.228Z,1665073801.228 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20221006T161517/Courier0004.lzma
2022-10-06T16:30:02.231Z,1665073802.231 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0004.lzma.bak
2022-10-06T16:30:02.231Z,1665073802.231 [DataOverHttps](INFO): SBD MOMSN=17235258
2022-10-06T16:30:13.769Z,1665073813.769 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:30:19.009Z,1665073819.009 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20221006T161517/Express0005.lzma
2022-10-06T16:30:20.011Z,1665073820.011 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0005.lzma.bak
2022-10-06T16:30:20.011Z,1665073820.011 [DataOverHttps](INFO): SBD MOMSN=17235260
2022-10-06T16:30:21.483Z,1665073821.483 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T16:30:21.483Z,1665073821.483 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T16:30:21.483Z,1665073821.483 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:30:28.028Z,1665073828.028 [CBIT](INFO): Clearing failed state for component DropWeight
2022-10-06T16:30:28.029Z,1665073828.029 [DropWeight] No Fault, FailCount= 1
2022-10-06T16:30:29.586Z,1665073829.586 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:30:31.209Z,1665073831.209 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-10-06T16:30:31.209Z,1665073831.209 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:30:31.223Z,1665073831.223 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:30:31.644Z,1665073831.644 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:30:31.644Z,1665073831.644 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-10-06T16:30:44.943Z,1665073844.943 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:30:59.895Z,1665073859.895 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:31:15.243Z,1665073875.243 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:31:31.402Z,1665073891.402 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:31:46.350Z,1665073906.350 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:32:01.297Z,1665073921.297 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:32:22.497Z,1665073942.497 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:32:53.622Z,1665073973.622 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:33:24.757Z,1665074004.757 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:33:32.254Z,1665074012.254 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-10-06T16:33:32.254Z,1665074012.254 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:33:32.266Z,1665074012.266 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:33:32.628Z,1665074012.628 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:33:32.628Z,1665074012.628 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-10-06T16:33:55.881Z,1665074035.881 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:34:27.005Z,1665074067.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:35:22.116Z,1665074122.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T16:35:22.116Z,1665074122.116 [Default:CheckIn:C.Wait] Stopped
2022-10-06T16:35:22.116Z,1665074122.116 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:35:22.116Z,1665074122.116 [Default:CheckIn:D] Running Loop=1
2022-10-06T16:35:22.528Z,1665074122.528 [Default:CheckIn:D] Stopped
2022-10-06T16:35:22.528Z,1665074122.528 [Default:CheckIn:E] Running Loop=1
2022-10-06T16:35:22.953Z,1665074122.953 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.912667 min 
2022-10-06T16:35:22.953Z,1665074122.953 [Default:CheckIn:E] Stopped
2022-10-06T16:35:22.953Z,1665074122.953 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn] Stopped
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn](INFO): Running loop #2
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn] Running Loop=2
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T16:35:22.954Z,1665074122.954 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T16:36:33.217Z,1665074193.217 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-10-06T16:36:33.217Z,1665074193.217 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:36:33.252Z,1665074193.252 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:36:33.661Z,1665074193.661 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:36:33.661Z,1665074193.661 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-10-06T16:36:52.587Z,1665074212.587 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-06T16:36:52.587Z,1665074212.587 [NAL9602] Data Fault, FailCount= 2
2022-10-06T16:36:52.587Z,1665074212.587 [NAL9602](ERROR): Data Fault
2022-10-06T16:36:52.649Z,1665074212.649 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-06T16:36:53.019Z,1665074213.019 [NAL9602](INFO): Powering down
2022-10-06T16:36:53.816Z,1665074213.816 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-06T16:36:53.816Z,1665074213.816 [NAL9602] No Fault, FailCount= 2
2022-10-06T16:37:23.288Z,1665074243.288 [NAL9602](INFO): Powering up NAL9602
2022-10-06T16:37:34.199Z,1665074254.199 [NAL9602](INFO): NAL9602 initialized
2022-10-06T16:39:16.062Z,1665074356.062 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2022-10-06T16:39:23.274Z,1665074363.274 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:39:34.242Z,1665074374.242 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2022-10-06T16:39:34.242Z,1665074374.242 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:39:34.254Z,1665074374.254 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:39:34.643Z,1665074374.643 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:39:34.643Z,1665074374.643 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2022-10-06T16:39:39.439Z,1665074379.439 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:39:54.786Z,1665074394.786 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:40:10.542Z,1665074410.542 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:40:23.236Z,1665074423.236 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-06T16:35:22.0Z
2022-10-06T16:40:23.236Z,1665074423.236 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T16:40:23.236Z,1665074423.236 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T16:40:25.490Z,1665074425.490 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:40:30.376Z,1665074430.376 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221006T161517/Courier0007.lzma
2022-10-06T16:40:31.379Z,1665074431.379 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0007.lzma.bak
2022-10-06T16:40:31.379Z,1665074431.379 [DataOverHttps](INFO): SBD MOMSN=17235265
2022-10-06T16:40:40.842Z,1665074440.842 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:40:46.849Z,1665074446.849 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20221006T161517/Express0008.lzma
2022-10-06T16:40:47.851Z,1665074447.851 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0008.lzma.bak
2022-10-06T16:40:47.851Z,1665074447.851 [DataOverHttps](INFO): SBD MOMSN=17235267
2022-10-06T16:40:49.343Z,1665074449.343 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T16:40:49.343Z,1665074449.343 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T16:40:49.343Z,1665074449.343 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:40:55.861Z,1665074455.861 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:41:11.216Z,1665074471.216 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:41:26.157Z,1665074486.157 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T16:42:35.326Z,1665074555.326 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2022-10-06T16:42:35.326Z,1665074555.326 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:42:35.353Z,1665074555.353 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:42:35.753Z,1665074555.753 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:42:35.753Z,1665074555.753 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2022-10-06T16:44:24.078Z,1665074664.078 [CommandExec](IMPORTANT): got command burn off
2022-10-06T16:44:24.078Z,1665074664.078 [CommandExec](IMPORTANT): Deactivating dropweight wire
2022-10-06T16:44:27.522Z,1665074667.522 [CommandExec](IMPORTANT): got command failComponent
2022-10-06T16:44:27.522Z,1665074667.522 [CommandExec](IMPORTANT): Failed components:
2022-10-06T16:44:27.522Z,1665074667.522 [CommandExec](IMPORTANT): No failed Components.
2022-10-06T16:45:36.349Z,1665074736.349 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2022-10-06T16:45:36.349Z,1665074736.349 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-06T16:45:36.360Z,1665074736.360 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-06T16:45:36.773Z,1665074736.773 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-06T16:45:36.773Z,1665074736.773 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2022-10-06T16:45:50.114Z,1665074750.114 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T16:45:50.114Z,1665074750.114 [Default:CheckIn:C.Wait] Stopped
2022-10-06T16:45:50.115Z,1665074750.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:45:50.115Z,1665074750.115 [Default:CheckIn:D] Running Loop=1
2022-10-06T16:45:50.519Z,1665074750.519 [Default:CheckIn:D] Stopped
2022-10-06T16:45:50.520Z,1665074750.520 [Default:CheckIn:E] Running Loop=1
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.379197 min 
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn:E] Stopped
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn] Stopped
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T16:45:50.916Z,1665074750.916 [Default:CheckIn](INFO): Running loop #3
2022-10-06T16:45:50.917Z,1665074750.917 [Default:CheckIn] Running Loop=3
2022-10-06T16:45:50.917Z,1665074750.917 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T16:45:50.917Z,1665074750.917 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T16:46:27.662Z,1665074787.662 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5.
2022-10-06T16:46:27.666Z,1665074787.666 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2022-10-06T16:47:04.869Z,1665074824.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164703.00,A,3648.16773,N,12147.27551,W,0.330,0.00,061022,,,A*74
2022-10-06T16:47:04.872Z,1665074824.872 [NAL9602](INFO): GPS fix at 20221006T164703: (36.802796, -121.787925)
2022-10-06T16:47:04.882Z,1665074824.882 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T16:47:04.882Z,1665074824.882 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T16:47:13.769Z,1665074833.769 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20221006T161517/Courier0010.lzma
2022-10-06T16:47:14.771Z,1665074834.771 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0010.lzma.bak
2022-10-06T16:47:14.771Z,1665074834.771 [DataOverHttps](INFO): SBD MOMSN=17235274
2022-10-06T16:47:31.357Z,1665074851.357 [DataOverHttps](INFO): Sending 334 bytes from file Logs/20221006T161517/Express0011.lzma
2022-10-06T16:47:32.359Z,1665074852.359 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0011.lzma.bak
2022-10-06T16:47:32.359Z,1665074852.359 [DataOverHttps](INFO): SBD MOMSN=17235278
2022-10-06T16:47:33.828Z,1665074853.828 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T16:47:33.828Z,1665074853.828 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T16:47:33.828Z,1665074853.828 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:47:37.442Z,1665074857.442 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T16:52:34.391Z,1665075154.391 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T16:52:34.392Z,1665075154.392 [Default:CheckIn:C.Wait] Stopped
2022-10-06T16:52:34.392Z,1665075154.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:52:34.392Z,1665075154.392 [Default:CheckIn:D] Running Loop=1
2022-10-06T16:52:34.805Z,1665075154.805 [Default:CheckIn:D] Stopped
2022-10-06T16:52:34.805Z,1665075154.805 [Default:CheckIn:E] Running Loop=1
2022-10-06T16:52:35.202Z,1665075155.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.117287 min 
2022-10-06T16:52:35.202Z,1665075155.202 [Default:CheckIn:E] Stopped
2022-10-06T16:52:35.202Z,1665075155.202 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T16:52:35.202Z,1665075155.202 [Default:CheckIn] Stopped
2022-10-06T16:52:35.202Z,1665075155.202 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T16:52:35.203Z,1665075155.203 [Default:CheckIn](INFO): Running loop #4
2022-10-06T16:52:35.203Z,1665075155.203 [Default:CheckIn] Running Loop=4
2022-10-06T16:52:35.203Z,1665075155.203 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T16:52:35.203Z,1665075155.203 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T16:52:37.216Z,1665075157.216 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165236.00,A,3648.16468,N,12147.28291,W,0.369,201.11,061022,,,A*74
2022-10-06T16:52:37.228Z,1665075157.228 [NAL9602](INFO): GPS fix at 20221006T165236: (36.802745, -121.788049)
2022-10-06T16:52:37.238Z,1665075157.238 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T16:52:37.238Z,1665075157.238 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T16:52:44.921Z,1665075164.921 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221006T161517/Courier0013.lzma
2022-10-06T16:52:45.923Z,1665075165.923 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0013.lzma.bak
2022-10-06T16:52:45.923Z,1665075165.923 [DataOverHttps](INFO): SBD MOMSN=17235321
2022-10-06T16:53:01.103Z,1665075181.103 [CommandExec](IMPORTANT): got command show variable buoyancy
2022-10-06T16:53:01.106Z,1665075181.106 [CommandExec](IMPORTANT): platform_buoyancy_position (cubic_centimeter)
2022-10-06T16:53:01.113Z,1665075181.113 [CommandExec](IMPORTANT): Simulator.initBuoyancyPosition (cubic_centimeter)
2022-10-06T16:53:01.116Z,1665075181.116 [CommandExec](IMPORTANT): Simulator.centerHystBuoyancy (cubic_centimeter)
2022-10-06T16:53:01.117Z,1665075181.117 [CommandExec](IMPORTANT): Simulator.speedBuoyancy (cubic_centimeter_per_second)
2022-10-06T16:53:01.117Z,1665075181.117 [CommandExec](IMPORTANT): Simulator.wideHystBuoyancy (cubic_centimeter)
2022-10-06T16:53:01.118Z,1665075181.118 [CommandExec](IMPORTANT): Simulator.buoyancyNeutralOffset (cubic_centimeter)
2022-10-06T16:53:01.119Z,1665075181.119 [CommandExec](IMPORTANT): VerticalControl.buoyancyDefault (cubic_centimeter)
2022-10-06T16:53:01.119Z,1665075181.119 [CommandExec](IMPORTANT): VerticalControl.buoyancyLimitHiCC (cubic_centimeter)
2022-10-06T16:53:01.120Z,1665075181.120 [CommandExec](IMPORTANT): VerticalControl.buoyancyLimitLoCC (cubic_centimeter)
2022-10-06T16:53:01.120Z,1665075181.120 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter)
2022-10-06T16:53:01.120Z,1665075181.120 [CommandExec](IMPORTANT): VerticalControl.buoyancyPumpDepth (meter)
2022-10-06T16:53:01.123Z,1665075181.123 [CommandExec](IMPORTANT): BuoyancyServo.loadAtStartup (bool)
2022-10-06T16:53:01.123Z,1665075181.123 [CommandExec](IMPORTANT): BuoyancyServo.simulateHardware (bool)
2022-10-06T16:53:01.124Z,1665075181.124 [CommandExec](IMPORTANT): BuoyancyServo.accel (none)
2022-10-06T16:53:01.124Z,1665075181.124 [CommandExec](IMPORTANT): BuoyancyServo.currLimit (percent)
2022-10-06T16:53:01.124Z,1665075181.124 [CommandExec](IMPORTANT): BuoyancyServo.limitHi (count)
2022-10-06T16:53:01.125Z,1665075181.125 [CommandExec](IMPORTANT): BuoyancyServo.limitLo (count)
2022-10-06T16:53:01.185Z,1665075181.185 [CommandExec](IMPORTANT): BuoyancyServo.overloadTimeout (millisecond)
2022-10-06T16:53:01.186Z,1665075181.186 [CommandExec](IMPORTANT): BuoyancyServo.pidW (count)
2022-10-06T16:53:01.186Z,1665075181.186 [CommandExec](IMPORTANT): BuoyancyServo.pidX (count)
2022-10-06T16:53:01.186Z,1665075181.186 [CommandExec](IMPORTANT): BuoyancyServo.pidY (count)
2022-10-06T16:53:01.187Z,1665075181.187 [CommandExec](IMPORTANT): BuoyancyServo.powerOffTimeout (second)
2022-10-06T16:53:01.187Z,1665075181.187 [CommandExec](IMPORTANT): BuoyancyServo.powerOnTimeout (second)
2022-10-06T16:53:01.187Z,1665075181.187 [CommandExec](IMPORTANT): BuoyancyServo.velocity (none)
2022-10-06T16:53:01.188Z,1665075181.188 [CommandExec](IMPORTANT): BuoyancyServo.checkingTimeout (minute)
2022-10-06T16:53:01.188Z,1665075181.188 [CommandExec](IMPORTANT): BuoyancyServo.countsPerCC (count_per_cubic_centimeter)
2022-10-06T16:53:01.189Z,1665075181.189 [CommandExec](IMPORTANT): BuoyancyServo.deviationVolume (cubic_centimeter)
2022-10-06T16:53:01.209Z,1665075181.209 [CommandExec](IMPORTANT): BuoyancyServo.fastPumpCoefficient (none)
2022-10-06T16:53:01.210Z,1665075181.210 [CommandExec](IMPORTANT): BuoyancyServo.fastPumpDepth (meter)
2022-10-06T16:53:01.210Z,1665075181.210 [CommandExec](IMPORTANT): BuoyancyServo.offsetVolume (cubic_centimeter)
2022-10-06T16:53:01.257Z,1665075181.257 [CommandExec](IMPORTANT): BuoyancyServo.loadControl (none)
2022-10-06T16:53:01.258Z,1665075181.258 [CommandExec](IMPORTANT): BuoyancyServo.uart (none)
2022-10-06T16:53:01.258Z,1665075181.258 [CommandExec](IMPORTANT): BuoyancyServo.baud (bit_per_second)
2022-10-06T16:53:01.435Z,1665075181.435 [CommandExec](IMPORTANT): VerticalControl.buoyancyAction (cubic_centimeter)
2022-10-06T16:53:01.437Z,1665075181.437 [CommandExec](IMPORTANT): BuoyancyServo.enableBroadcast (bool)
2022-10-06T16:53:01.437Z,1665075181.437 [CommandExec](IMPORTANT): BuoyancyServo.component_voltage (volt)
2022-10-06T16:53:01.437Z,1665075181.437 [CommandExec](IMPORTANT): BuoyancyServo.component_avgVoltage (volt)
2022-10-06T16:53:01.438Z,1665075181.438 [CommandExec](IMPORTANT): BuoyancyServo.component_current (milliampere)
2022-10-06T16:53:01.438Z,1665075181.438 [CommandExec](IMPORTANT): BuoyancyServo.component_avgCurrent (milliampere)
2022-10-06T16:53:01.439Z,1665075181.439 [CommandExec](IMPORTANT): BuoyancyServo.platform_buoyancy_position (cubic_centimeter)
2022-10-06T16:53:05.853Z,1665075185.853 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221006T161517/Express0014.lzma
2022-10-06T16:53:06.855Z,1665075186.855 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0014.lzma.bak
2022-10-06T16:53:06.855Z,1665075186.855 [DataOverHttps](INFO): SBD MOMSN=17235324
2022-10-06T16:53:07.997Z,1665075187.997 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T16:53:07.998Z,1665075187.998 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T16:53:07.998Z,1665075187.998 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:53:45.143Z,1665075225.143 [NAL9602](INFO): SBD MO Status=2, MOMSN=36591, MT Status=2, MTMSN=0
2022-10-06T16:53:45.144Z,1665075225.144 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-06T16:53:55.556Z,1665075235.556 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300 cubic_centimeter
2022-10-06T16:53:55.559Z,1665075235.559 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2022-10-06T16:53:55.659Z,1665075235.659 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-10-06T16:54:57.043Z,1665075297.043 [NAL9602](INFO): SBD MO Status=2, MOMSN=36591, MT Status=2, MTMSN=0
2022-10-06T16:54:57.043Z,1665075297.043 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-06T16:55:04.695Z,1665075304.695 [CommandExec](IMPORTANT): got command maintain clear
2022-10-06T16:55:04.743Z,1665075304.743 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-10-06T16:56:18.815Z,1665075378.815 [DataOverHttps](IMPORTANT): SBD MTMSN=20221006T165617
2022-10-06T16:56:28.906Z,1665075388.906 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-10-06T16:56:29.001Z,1665075389.001 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-06T16:56:29.007Z,1665075389.007 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-06T16:56:29.134Z,1665075389.134 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-10-06T16:56:29.136Z,1665075389.136 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-10-06T16:56:29.143Z,1665075389.143 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-10-06T16:56:29.154Z,1665075389.154 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-10-06T16:56:29.161Z,1665075389.161 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-10-06T16:56:29.164Z,1665075389.164 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-10-06T16:56:29.167Z,1665075389.167 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-10-06T16:56:29.214Z,1665075389.214 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-10-06T16:56:29.221Z,1665075389.221 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-10-06T16:56:29.224Z,1665075389.224 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-10-06T16:56:29.236Z,1665075389.236 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-10-06T16:56:29.263Z,1665075389.263 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-10-06T16:56:29.274Z,1665075389.274 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-10-06T16:56:29.306Z,1665075389.306 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-10-06T16:56:29.306Z,1665075389.306 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-10-06T16:56:29.831Z,1665075389.831 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-10-06T16:56:29.856Z,1665075389.856 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-10-06T16:56:29.859Z,1665075389.859 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-10-06T16:56:29.861Z,1665075389.861 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-10-06T16:56:29.864Z,1665075389.864 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-10-06T16:56:29.866Z,1665075389.866 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-10-06T16:56:29.868Z,1665075389.868 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-10-06T16:56:29.871Z,1665075389.871 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-10-06T16:56:29.930Z,1665075389.930 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-10-06T16:56:29.933Z,1665075389.933 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-10-06T16:56:29.935Z,1665075389.935 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-10-06T16:56:29.966Z,1665075389.966 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-10-06T16:56:29.969Z,1665075389.969 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-10-06T16:56:29.971Z,1665075389.971 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-10-06T16:56:30.030Z,1665075390.030 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-10-06T16:56:30.041Z,1665075390.041 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-10-06T16:56:30.045Z,1665075390.045 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-10-06T16:56:30.068Z,1665075390.068 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-10-06T16:56:30.080Z,1665075390.080 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-10-06T16:56:30.100Z,1665075390.100 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-10-06T16:56:30.129Z,1665075390.129 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2022-10-06T16:56:30.135Z,1665075390.135 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-10-06T16:56:30.142Z,1665075390.142 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-10-06T16:56:30.162Z,1665075390.162 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-10-06T16:56:30.164Z,1665075390.164 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-10-06T16:56:30.176Z,1665075390.176 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-10-06T16:56:30.183Z,1665075390.183 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-10-06T16:56:30.211Z,1665075390.211 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-10-06T16:56:30.222Z,1665075390.222 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-10-06T16:56:30.225Z,1665075390.225 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-10-06T16:56:30.227Z,1665075390.227 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-10-06T16:56:30.248Z,1665075390.248 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-10-06T16:56:30.251Z,1665075390.251 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-10-06T16:56:30.290Z,1665075390.290 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-10-06T16:56:30.293Z,1665075390.293 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-10-06T16:56:30.296Z,1665075390.296 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-10-06T16:56:30.319Z,1665075390.319 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-10-06T16:56:30.327Z,1665075390.327 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-10-06T16:56:30.335Z,1665075390.335 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-10-06T16:56:30.358Z,1665075390.358 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-10-06T16:56:30.361Z,1665075390.361 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-10-06T16:56:30.372Z,1665075390.372 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-10-06T16:56:30.422Z,1665075390.422 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-10-06T16:56:30.424Z,1665075390.424 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-10-06T16:56:30.452Z,1665075390.452 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-10-06T16:56:30.456Z,1665075390.456 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-10-06T16:56:30.471Z,1665075390.471 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-10-06T16:56:30.478Z,1665075390.478 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-10-06T16:56:30.489Z,1665075390.489 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-10-06T16:56:30.492Z,1665075390.492 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-10-06T16:56:30.500Z,1665075390.500 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-10-06T16:56:30.507Z,1665075390.507 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-10-06T16:56:30.518Z,1665075390.518 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-10-06T16:56:30.537Z,1665075390.537 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-10-06T16:56:30.541Z,1665075390.541 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-10-06T16:56:30.544Z,1665075390.544 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-10-06T16:56:30.547Z,1665075390.547 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-10-06T16:56:30.566Z,1665075390.566 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-10-06T16:56:30.569Z,1665075390.569 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-10-06T16:56:30.572Z,1665075390.572 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-10-06T16:56:30.575Z,1665075390.575 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-10-06T16:56:30.594Z,1665075390.594 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-10-06T16:56:30.597Z,1665075390.597 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-10-06T16:56:30.601Z,1665075390.601 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-10-06T16:56:30.604Z,1665075390.604 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-10-06T16:56:30.690Z,1665075390.690 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-06T16:56:30.722Z,1665075390.722 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-06T16:56:30.778Z,1665075390.778 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-06T16:56:30.800Z,1665075390.800 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-06T16:56:30.867Z,1665075390.867 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-06T16:56:30.920Z,1665075390.920 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-06T16:56:30.956Z,1665075390.956 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-06T16:56:31.002Z,1665075391.002 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-06T16:56:31.012Z,1665075391.012 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-10-06T16:56:31.365Z,1665075391.365 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-10-06T16:56:31.368Z,1665075391.368 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-10-06T16:56:31.371Z,1665075391.371 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-10-06T16:56:31.382Z,1665075391.382 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-10-06T16:56:31.390Z,1665075391.390 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-10-06T16:56:31.404Z,1665075391.404 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-10-06T16:56:31.419Z,1665075391.419 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-10-06T16:56:31.422Z,1665075391.422 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-10-06T16:56:31.425Z,1665075391.425 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-10-06T16:56:31.428Z,1665075391.428 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-10-06T16:56:31.454Z,1665075391.454 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-10-06T16:56:31.457Z,1665075391.457 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-10-06T16:56:31.460Z,1665075391.460 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-10-06T16:56:31.467Z,1665075391.467 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-10-06T16:56:31.510Z,1665075391.510 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-10-06T16:56:31.517Z,1665075391.517 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-10-06T16:56:31.521Z,1665075391.521 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-10-06T16:56:31.550Z,1665075391.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-10-06T16:56:31.557Z,1665075391.557 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-10-06T16:56:31.560Z,1665075391.560 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-10-06T16:56:31.585Z,1665075391.585 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-10-06T16:56:31.639Z,1665075391.639 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-10-06T16:56:31.650Z,1665075391.650 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-10-06T16:56:31.681Z,1665075391.681 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-10-06T16:56:31.717Z,1665075391.717 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-10-06T16:56:31.756Z,1665075391.756 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-10-06T16:56:31.758Z,1665075391.758 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-10-06T16:56:31.759Z,1665075391.759 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-10-06T16:56:31.778Z,1665075391.778 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-10-06T16:56:31.780Z,1665075391.780 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-10-06T16:56:31.782Z,1665075391.782 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-10-06T16:56:31.783Z,1665075391.783 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-10-06T16:56:31.785Z,1665075391.785 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-10-06T16:56:31.808Z,1665075391.808 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-10-06T16:56:31.812Z,1665075391.812 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-10-06T16:56:31.907Z,1665075391.907 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="ballast_and_trim">

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

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

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

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

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

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

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

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

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

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

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

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

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

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

    <Timeout Duration="MissionTimeout"/>

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

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

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

        <Aggregate Id="Depth1">

            <Sequence/>

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

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

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

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

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

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

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

        <Sequence/>

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

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

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

    </Aggregate>

</Mission>


2022-10-06T16:56:31.910Z,1665075391.910 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-06T16:56:32.061Z,1665075392.061 [Default] Stopped
2022-10-06T16:56:32.061Z,1665075392.061 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-06T16:56:32.061Z,1665075392.061 [Default:B.GoToSurface] Stopped
2022-10-06T16:56:32.065Z,1665075392.065 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-06T16:56:32.065Z,1665075392.065 [Default:CheckIn] Stopped
2022-10-06T16:56:32.065Z,1665075392.065 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T16:56:32.065Z,1665075392.065 [Default:CheckIn:C.Wait] Stopped
2022-10-06T16:56:32.065Z,1665075392.065 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:56:32.066Z,1665075392.066 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim] Running Loop=1
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science] Running Loop=1
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science:A] Running Loop=1
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science:B] Running Loop=1
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science:C] Running Loop=1
2022-10-06T16:56:32.066Z,1665075392.066 [ballast_and_trim:Science:D] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:E] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:F] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-10-06T16:56:32.067Z,1665075392.067 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-06T16:56:32.073Z,1665075392.073 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-10-06T16:56:32.073Z,1665075392.073 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-10-06T16:56:32.073Z,1665075392.073 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-06T16:56:32.074Z,1665075392.074 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-06T16:56:32.074Z,1665075392.074 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-10-06T16:56:32.074Z,1665075392.074 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-10-06T16:56:32.074Z,1665075392.074 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-10-06T16:56:32.074Z,1665075392.074 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-06T16:56:32.076Z,1665075392.076 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-10-06T16:56:32.076Z,1665075392.076 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-10-06T16:56:32.076Z,1665075392.076 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-10-06T16:56:32.076Z,1665075392.076 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-10-06T16:56:32.083Z,1665075392.083 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-10-06T16:56:32.084Z,1665075392.084 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-10-06T16:56:32.084Z,1665075392.084 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-06T16:56:32.087Z,1665075392.087 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-10-06T16:56:32.087Z,1665075392.087 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-10-06T16:56:32.087Z,1665075392.087 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-10-06T16:56:32.087Z,1665075392.087 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-06T16:56:32.097Z,1665075392.097 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-10-06T16:56:32.097Z,1665075392.097 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-10-06T16:56:32.097Z,1665075392.097 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-06T16:56:32.097Z,1665075392.097 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-06T16:56:32.098Z,1665075392.098 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-10-06T16:56:32.098Z,1665075392.098 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-10-06T16:56:32.098Z,1665075392.098 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-10-06T16:56:32.098Z,1665075392.098 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-10-06T16:56:32.098Z,1665075392.098 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-10-06T16:56:32.099Z,1665075392.099 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-10-06T16:56:32.099Z,1665075392.099 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-10-06T16:56:32.099Z,1665075392.099 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-06T16:56:32.099Z,1665075392.099 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-10-06T16:56:32.100Z,1665075392.100 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-10-06T16:56:32.100Z,1665075392.100 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-10-06T16:56:32.100Z,1665075392.100 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-06T16:56:32.100Z,1665075392.100 [ballast_and_trim:Science] Running Loop=1
2022-10-06T16:56:32.105Z,1665075392.105 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-10-06T16:56:32.106Z,1665075392.106 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-10-06T16:56:32.107Z,1665075392.107 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-06T16:56:32.108Z,1665075392.108 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-10-06T16:56:32.109Z,1665075392.109 [ballast_and_trim:Science:Read_Oil] Stopped
2022-10-06T16:56:32.109Z,1665075392.109 [ballast_and_trim:Science:F] Stopped
2022-10-06T16:56:32.109Z,1665075392.109 [ballast_and_trim:Science:E] Running Loop=1
2022-10-06T16:56:32.110Z,1665075392.110 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-10-06T16:56:32.110Z,1665075392.110 [ballast_and_trim:Science:D] Stopped
2022-10-06T16:56:32.110Z,1665075392.110 [ballast_and_trim:Science:C] Running Loop=1
2022-10-06T16:56:32.111Z,1665075392.111 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-10-06T16:56:32.111Z,1665075392.111 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-10-06T16:56:32.111Z,1665075392.111 [ballast_and_trim:Science:B] Running Loop=1
2022-10-06T16:56:32.112Z,1665075392.112 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-10-06T16:56:32.113Z,1665075392.113 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-10-06T16:56:32.113Z,1665075392.113 [ballast_and_trim:Science:A] Stopped
2022-10-06T16:56:32.191Z,1665075392.191 [WetLabsBB2FL](INFO): Powering up
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-10-06T16:56:32.456Z,1665075392.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-10-06T16:56:32.457Z,1665075392.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-10-06T16:56:32.471Z,1665075392.471 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-10-06T16:56:32.471Z,1665075392.471 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-10-06T16:56:32.471Z,1665075392.471 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-10-06T16:56:32.471Z,1665075392.471 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-10-06T16:56:32.472Z,1665075392.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-10-06T16:56:32.473Z,1665075392.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-10-06T16:56:32.473Z,1665075392.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-06T16:56:32.473Z,1665075392.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-10-06T16:56:32.477Z,1665075392.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-10-06T16:56:32.477Z,1665075392.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-10-06T16:56:32.478Z,1665075392.478 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-10-06T16:56:32.478Z,1665075392.478 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-10-06T16:56:32.478Z,1665075392.478 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-10-06T16:56:32.892Z,1665075392.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-10-06T16:56:32.893Z,1665075392.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-10-06T16:56:32.893Z,1665075392.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-10-06T16:56:32.893Z,1665075392.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-10-06T16:56:32.893Z,1665075392.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-10-06T16:56:32.897Z,1665075392.897 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-10-06T16:56:32.897Z,1665075392.897 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-10-06T16:56:32.897Z,1665075392.897 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-10-06T16:56:32.897Z,1665075392.897 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-10-06T16:56:32.897Z,1665075392.897 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-10-06T16:56:32.898Z,1665075392.898 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-10-06T16:56:33.270Z,1665075393.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-10-06T16:56:33.271Z,1665075393.271 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-10-06T16:56:33.272Z,1665075393.272 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-10-06T16:56:33.682Z,1665075393.682 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-10-06T16:56:33.683Z,1665075393.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-10-06T16:56:33.683Z,1665075393.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-10-06T16:56:33.683Z,1665075393.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-10-06T16:56:33.683Z,1665075393.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-10-06T16:56:35.455Z,1665075395.455 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-10-06T16:57:39.582Z,1665075459.582 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T16:58:10.286Z,1665075490.286 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T16:58:51.073Z,1665075531.073 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:59:03.125Z,1665075543.125 [Radio_Surface](INFO): Powering down
2022-10-06T16:59:22.197Z,1665075562.197 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T16:59:23.202Z,1665075563.202 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-10-06T17:00:28.083Z,1665075628.083 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-10-06T17:00:28.084Z,1665075628.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-06T17:00:28.084Z,1665075628.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-10-06T17:00:28.084Z,1665075628.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-06T17:00:28.084Z,1665075628.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-10-06T17:00:28.085Z,1665075628.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-10-06T17:00:28.085Z,1665075628.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-06T17:00:28.085Z,1665075628.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-10-06T17:00:28.086Z,1665075628.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-10-06T17:00:28.087Z,1665075628.087 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-10-06T17:00:28.087Z,1665075628.087 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-10-06T17:00:28.087Z,1665075628.087 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.026423 m 
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-10-06T17:00:28.476Z,1665075628.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-10-06T17:00:59.590Z,1665075659.590 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.727234
2022-10-06T17:10:28.870Z,1665076228.870 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-10-06T17:10:28.870Z,1665076228.870 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-10-06T17:10:28.870Z,1665076228.870 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:10:28.871Z,1665076228.871 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-10-06T17:10:29.239Z,1665076229.239 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 7.083615 m 
2022-10-06T17:10:29.239Z,1665076229.239 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-10-06T17:10:29.239Z,1665076229.239 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-10-06T17:10:29.239Z,1665076229.239 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-10-06T17:27:05.123Z,1665077225.123 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 16.59 minutes.
2022-10-06T17:27:05.124Z,1665077225.124 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 211.596552 +/- 14.997685 cc (conf. level 99.90%, sigma: 22.912468 cc).
2022-10-06T17:27:05.125Z,1665077225.125 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: -9.807334 +/- 0.195325 mm (conf. level 99.90%, sigma: 0.298405 mm).
2022-10-06T17:27:05.126Z,1665077225.126 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 211.596552 cc buoyancy neutral and -9.807334 mm mass default
2022-10-06T17:27:05.131Z,1665077225.131 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-10-06T17:27:05.132Z,1665077225.132 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AHRS_M2.readAccelerations=0 bool;

2022-10-06T17:27:05.132Z,1665077225.132 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AHRS_M2.readAngularVelocities=0 bool;

2022-10-06T17:27:05.132Z,1665077225.132 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AHRS_M2.readMagnetics=0 bool;

2022-10-06T17:27:05.132Z,1665077225.132 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2022-10-06T17:27:05.132Z,1665077225.132 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BPC1.batteryMissingStickThreshold=3 count;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CANONSampler.sampleTimeout=10 minute;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=0 bool;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2022-10-06T17:27:05.133Z,1665077225.133 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation NAL9602.sigQuality 1.000000 count;

2022-10-06T17:27:05.134Z,1665077225.134 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation ThrusterServo.component_avgCurrent 10.000000 milliampere;

2022-10-06T17:27:05.134Z,1665077225.134 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=211.596552 cubic_centimeter;

2022-10-06T17:27:05.134Z,1665077225.134 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=-9.807334 millimeter;

2022-10-06T17:27:05.134Z,1665077225.134 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-10-06T17:27:05.134Z,1665077225.134 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-10-06T17:27:05.135Z,1665077225.135 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-06T17:27:05.135Z,1665077225.135 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-10-06T17:27:05.135Z,1665077225.135 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-06T17:27:05.135Z,1665077225.135 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-10-06T17:27:05.135Z,1665077225.135 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-10-06T17:27:05.136Z,1665077225.136 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-10-06T17:27:05.137Z,1665077225.137 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-10-06T17:27:05.510Z,1665077225.510 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-06T17:27:05.510Z,1665077225.510 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-10-06T17:27:05.510Z,1665077225.510 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-10-06T17:27:05.511Z,1665077225.511 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2022-10-06T17:27:05.932Z,1665077225.932 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2022-10-06T17:27:05.933Z,1665077225.933 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-10-06T17:27:05.933Z,1665077225.933 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2022-10-06T17:27:05.933Z,1665077225.933 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-10-06T17:27:05.933Z,1665077225.933 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-10-06T17:27:05.937Z,1665077225.937 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-10-06T17:27:05.937Z,1665077225.937 [ballast_and_trim:Float_Up] Running Loop=1
2022-10-06T17:27:05.937Z,1665077225.937 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2022-10-06T17:27:05.938Z,1665077225.938 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-10-06T17:27:05.938Z,1665077225.938 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-10-06T17:27:05.938Z,1665077225.938 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2022-10-06T17:27:05.938Z,1665077225.938 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:27:06.320Z,1665077226.320 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-10-06T17:28:56.614Z,1665077336.614 [ballast_and_trim:Float_Up] Stopped
2022-10-06T17:28:56.614Z,1665077336.614 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2022-10-06T17:28:56.614Z,1665077336.614 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2022-10-06T17:28:56.614Z,1665077336.614 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-10-06T17:28:56.615Z,1665077336.615 [ballast_and_trim:Float_Up:B.Wait] Stopped
2022-10-06T17:28:56.615Z,1665077336.615 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:28:56.616Z,1665077336.616 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-10-06T17:28:56.616Z,1665077336.616 [MissionManager](INFO): ballast_and_trim is completed.
2022-10-06T17:28:56.616Z,1665077336.616 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-10-06T17:28:56.617Z,1665077336.617 [ballast_and_trim] Stopped
2022-10-06T17:28:56.617Z,1665077336.617 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-10-06T17:28:56.617Z,1665077336.617 [ballast_and_trim:Science] Stopped
2022-10-06T17:28:56.617Z,1665077336.617 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:B] Stopped
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:C] Stopped
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:E] Stopped
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-10-06T17:28:56.618Z,1665077336.618 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-10-06T17:28:56.933Z,1665077336.933 [WetLabsBB2FL](INFO): Powering down
2022-10-06T17:28:57.044Z,1665077337.044 [MissionManager](IMPORTANT): Started mission Default
2022-10-06T17:28:57.044Z,1665077337.044 [Default] Running Loop=1
2022-10-06T17:28:57.044Z,1665077337.044 [Default](DEBUG): Aggregate::initialize Default
2022-10-06T17:28:57.044Z,1665077337.044 [Default:B.GoToSurface] Running Loop=1
2022-10-06T17:28:57.044Z,1665077337.044 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-06T17:28:57.044Z,1665077337.044 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-06T17:28:57.045Z,1665077337.045 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-06T17:28:57.045Z,1665077337.045 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-06T17:28:57.046Z,1665077337.046 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-06T17:28:57.046Z,1665077337.046 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-06T17:28:57.046Z,1665077337.046 [Default:A.Wait] Running Loop=1
2022-10-06T17:28:57.046Z,1665077337.046 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:28:57.329Z,1665077337.329 [Radio_Surface](INFO): Powering up
2022-10-06T17:29:02.655Z,1665077342.655 [DataOverHttps](INFO): Radio surface powered ON.
2022-10-06T17:29:10.358Z,1665077350.358 [Default:A.Wait](INFO): Done Waiting.
2022-10-06T17:29:10.359Z,1665077350.359 [Default:A.Wait] Stopped
2022-10-06T17:29:10.359Z,1665077350.359 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:29:10.758Z,1665077350.758 [Default:CheckIn] Running Loop=1
2022-10-06T17:29:10.758Z,1665077350.758 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T17:29:10.758Z,1665077350.758 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T17:29:32.773Z,1665077372.773 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:29:43.475Z,1665077383.475 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-06T17:29:43.549Z,1665077383.549 [NAL9602](ERROR): received: 
+CSQ:0

OK591, 2, 0, 0, 0

OK
2022-10-06T17:30:03.897Z,1665077403.897 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:30:35.021Z,1665077435.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:31:06.153Z,1665077466.153 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:31:37.282Z,1665077497.282 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:32:08.406Z,1665077528.406 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-06T17:32:36.834Z,1665077556.834 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003707
2022-10-06T17:34:10.956Z,1665077650.956 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-06T17:29:10.8Z
2022-10-06T17:34:10.956Z,1665077650.956 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T17:34:10.956Z,1665077650.956 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T17:34:15.355Z,1665077655.355 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T17:34:17.869Z,1665077657.869 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221006T161517/Courier0016.lzma
2022-10-06T17:34:18.871Z,1665077658.871 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0016.lzma.bak
2022-10-06T17:34:18.871Z,1665077658.871 [DataOverHttps](INFO): SBD MOMSN=17235551
2022-10-06T17:34:37.402Z,1665077677.402 [DataOverHttps](INFO): Sending 1847 bytes from file Logs/20221006T161517/Express0017.lzma
2022-10-06T17:34:38.395Z,1665077678.395 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0017.lzma.bak
2022-10-06T17:34:38.395Z,1665077678.395 [DataOverHttps](INFO): SBD MOMSN=17235553
2022-10-06T17:34:46.121Z,1665077686.121 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T17:34:57.485Z,1665077697.485 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20221006T161517/Express0020.lzma
2022-10-06T17:34:58.487Z,1665077698.487 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0020.lzma.bak
2022-10-06T17:34:58.487Z,1665077698.487 [DataOverHttps](INFO): SBD MOMSN=17235624
2022-10-06T17:34:59.926Z,1665077699.926 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T17:34:59.926Z,1665077699.926 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T17:34:59.927Z,1665077699.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:40:00.505Z,1665078000.505 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T17:40:00.505Z,1665078000.505 [Default:CheckIn:C.Wait] Stopped
2022-10-06T17:40:00.505Z,1665078000.505 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:40:00.506Z,1665078000.506 [Default:CheckIn:D] Running Loop=1
2022-10-06T17:40:00.896Z,1665078000.896 [Default:CheckIn:D] Stopped
2022-10-06T17:40:00.896Z,1665078000.896 [Default:CheckIn:E] Running Loop=1
2022-10-06T17:40:01.307Z,1665078001.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.064200 min 
2022-10-06T17:40:01.307Z,1665078001.307 [Default:CheckIn:E] Stopped
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn] Stopped
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn](INFO): Running loop #2
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn] Running Loop=2
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T17:40:01.308Z,1665078001.308 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T17:40:02.905Z,1665078002.905 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-06T17:40:02.906Z,1665078002.906 [NAL9602] Data Fault, FailCount= 3
2022-10-06T17:40:02.906Z,1665078002.906 [NAL9602](ERROR): Data Fault
2022-10-06T17:40:02.926Z,1665078002.926 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-06T17:40:03.317Z,1665078003.317 [NAL9602](INFO): Powering down
2022-10-06T17:40:04.161Z,1665078004.161 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-06T17:40:04.162Z,1665078004.162 [NAL9602] No Fault, FailCount= 3
2022-10-06T17:40:33.630Z,1665078033.630 [NAL9602](INFO): Powering up NAL9602
2022-10-06T17:40:44.535Z,1665078044.535 [NAL9602](INFO): NAL9602 initialized
2022-10-06T17:45:01.556Z,1665078301.556 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-06T17:40:01.3Z
2022-10-06T17:45:01.556Z,1665078301.556 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T17:45:01.556Z,1665078301.556 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T17:45:08.932Z,1665078308.932 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221006T161517/Courier0022.lzma
2022-10-06T17:45:09.935Z,1665078309.935 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0022.lzma.bak
2022-10-06T17:45:09.935Z,1665078309.935 [DataOverHttps](INFO): SBD MOMSN=17235626
2022-10-06T17:45:26.025Z,1665078326.025 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20221006T161517/Express0023.lzma
2022-10-06T17:45:27.027Z,1665078327.027 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0023.lzma.bak
2022-10-06T17:45:27.027Z,1665078327.027 [DataOverHttps](INFO): SBD MOMSN=17235628
2022-10-06T17:45:28.166Z,1665078328.166 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T17:45:28.166Z,1665078328.166 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T17:45:28.166Z,1665078328.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:45:47.949Z,1665078347.949 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T17:46:18.654Z,1665078378.654 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T17:50:28.776Z,1665078628.776 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T17:50:28.776Z,1665078628.776 [Default:CheckIn:C.Wait] Stopped
2022-10-06T17:50:28.776Z,1665078628.776 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:50:28.776Z,1665078628.776 [Default:CheckIn:D] Running Loop=1
2022-10-06T17:50:29.188Z,1665078629.188 [Default:CheckIn:D] Stopped
2022-10-06T17:50:29.188Z,1665078629.188 [Default:CheckIn:E] Running Loop=1
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.535738 min 
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn:E] Stopped
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn] Stopped
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn](INFO): Running loop #3
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn] Running Loop=3
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T17:50:29.599Z,1665078629.599 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T17:50:31.608Z,1665078631.608 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175029.00,A,3648.16594,N,12147.28159,W,0.175,0.00,061022,,,A*70
2022-10-06T17:50:31.621Z,1665078631.621 [NAL9602](INFO): GPS fix at 20221006T175029: (36.802766, -121.788027)
2022-10-06T17:50:31.632Z,1665078631.632 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T17:50:31.632Z,1665078631.632 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T17:50:38.989Z,1665078638.989 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221006T161517/Courier0025.lzma
2022-10-06T17:50:39.991Z,1665078639.991 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0025.lzma.bak
2022-10-06T17:50:39.991Z,1665078639.991 [DataOverHttps](INFO): SBD MOMSN=17235634
2022-10-06T17:50:59.249Z,1665078659.249 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221006T161517/Express0026.lzma
2022-10-06T17:51:00.251Z,1665078660.251 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0026.lzma.bak
2022-10-06T17:51:00.251Z,1665078660.251 [DataOverHttps](INFO): SBD MOMSN=17235637
2022-10-06T17:51:01.552Z,1665078661.552 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T17:51:01.553Z,1665078661.553 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T17:51:01.553Z,1665078661.553 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:51:02.343Z,1665078662.343 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-06T17:51:02.421Z,1665078662.421 [NAL9602](ERROR): received: 
+CSQ:0

OK591, 2, 0, 0, 0

OK
2022-10-06T17:51:08.808Z,1665078668.808 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-10-06T17:51:24.559Z,1665078684.559 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:51:31.024Z,1665078691.024 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:51:46.375Z,1665078706.375 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:52:01.323Z,1665078721.323 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:52:16.678Z,1665078736.678 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:52:32.040Z,1665078752.040 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:52:47.379Z,1665078767.379 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:53:03.135Z,1665078783.135 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:53:18.084Z,1665078798.084 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:53:33.032Z,1665078813.032 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T17:55:42.371Z,1665078942.371 [NAL9602](INFO): SBD MO Status=2, MOMSN=36591, MT Status=2, MTMSN=0
2022-10-06T17:55:42.371Z,1665078942.371 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-06T17:55:42.731Z,1665078942.731 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T17:56:02.135Z,1665078962.135 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T17:56:02.135Z,1665078962.135 [Default:CheckIn:C.Wait] Stopped
2022-10-06T17:56:02.135Z,1665078962.135 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T17:56:02.135Z,1665078962.135 [Default:CheckIn:D] Running Loop=1
2022-10-06T17:56:02.523Z,1665078962.523 [Default:CheckIn:D] Stopped
2022-10-06T17:56:02.523Z,1665078962.523 [Default:CheckIn:E] Running Loop=1
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.091315 min 
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn:E] Stopped
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn] Stopped
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T17:56:02.933Z,1665078962.933 [Default:CheckIn](INFO): Running loop #4
2022-10-06T17:56:02.934Z,1665078962.934 [Default:CheckIn] Running Loop=4
2022-10-06T17:56:02.934Z,1665078962.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T17:56:02.934Z,1665078962.934 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T17:56:04.940Z,1665078964.940 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175604.00,A,3648.17107,N,12147.27831,W,0.292,0.00,061022,,,A*74
2022-10-06T17:56:04.942Z,1665078964.942 [NAL9602](INFO): GPS fix at 20221006T175604: (36.802851, -121.787972)
2022-10-06T17:56:04.975Z,1665078964.975 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T17:56:04.975Z,1665078964.975 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T17:56:12.533Z,1665078972.533 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221006T161517/Courier0028.lzma
2022-10-06T17:56:13.535Z,1665078973.535 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0028.lzma.bak
2022-10-06T17:56:13.535Z,1665078973.535 [DataOverHttps](INFO): SBD MOMSN=17235641
2022-10-06T17:56:32.867Z,1665078992.867 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20221006T161517/Express0029.lzma
2022-10-06T17:56:33.867Z,1665078993.867 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0029.lzma.bak
2022-10-06T17:56:33.867Z,1665078993.867 [DataOverHttps](INFO): SBD MOMSN=17235644
2022-10-06T17:56:35.313Z,1665078995.313 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T17:56:35.313Z,1665078995.313 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T17:56:35.313Z,1665078995.313 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T17:56:37.320Z,1665078997.320 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T18:00:32.057Z,1665079232.057 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-10-06T18:00:32.057Z,1665079232.057 [DropWeight] Hardware Fault, FailCount= 1
2022-10-06T18:00:32.057Z,1665079232.057 [DropWeight](ERROR): Hardware Fault
2022-10-06T18:00:32.118Z,1665079232.118 [CBIT](INFO): Critical error at 20221006T180032
2022-10-06T18:00:32.118Z,1665079232.118 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-10-06T18:00:32.121Z,1665079232.121 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-10-06T18:00:32.156Z,1665079232.156 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-10-06T18:00:32.489Z,1665079232.489 [CBIT](INFO): Critical error at 20221006T180032
2022-10-06T18:00:54.279Z,1665079254.279 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:01:01.147Z,1665079261.147 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:01:16.499Z,1665079276.499 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:01:31.851Z,1665079291.851 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:01:35.907Z,1665079295.907 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T18:01:35.908Z,1665079295.908 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:01:35.908Z,1665079295.908 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:01:35.908Z,1665079295.908 [Default:CheckIn:D] Running Loop=1
2022-10-06T18:01:36.316Z,1665079296.316 [Default:CheckIn:D] Stopped
2022-10-06T18:01:36.316Z,1665079296.316 [Default:CheckIn:E] Running Loop=1
2022-10-06T18:01:36.728Z,1665079296.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.654533 min 
2022-10-06T18:01:36.728Z,1665079296.728 [Default:CheckIn:E] Stopped
2022-10-06T18:01:36.728Z,1665079296.728 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T18:01:36.728Z,1665079296.728 [Default:CheckIn] Stopped
2022-10-06T18:01:36.729Z,1665079296.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:01:36.729Z,1665079296.729 [Default:CheckIn](INFO): Running loop #5
2022-10-06T18:01:36.729Z,1665079296.729 [Default:CheckIn] Running Loop=5
2022-10-06T18:01:36.729Z,1665079296.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T18:01:36.729Z,1665079296.729 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T18:01:38.728Z,1665079298.728 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180138.00,A,3648.16616,N,12147.27921,W,0.311,0.00,061022,,,A*7A
2022-10-06T18:01:38.730Z,1665079298.730 [NAL9602](INFO): GPS fix at 20221006T180138: (36.802769, -121.787987)
2022-10-06T18:01:38.741Z,1665079298.741 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T18:01:38.741Z,1665079298.741 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T18:01:45.733Z,1665079305.733 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20221006T161517/Courier0031.lzma
2022-10-06T18:01:46.735Z,1665079306.735 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0031.lzma.bak
2022-10-06T18:01:46.735Z,1665079306.735 [DataOverHttps](INFO): SBD MOMSN=17235648
2022-10-06T18:01:47.796Z,1665079307.796 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:02:02.509Z,1665079322.509 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221006T161517/Express0032.lzma
2022-10-06T18:02:03.135Z,1665079323.135 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:02:03.511Z,1665079323.511 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0032.lzma.bak
2022-10-06T18:02:03.511Z,1665079323.511 [DataOverHttps](INFO): SBD MOMSN=17235653
2022-10-06T18:02:04.787Z,1665079324.787 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T18:02:04.787Z,1665079324.787 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T18:02:04.787Z,1665079324.787 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T18:02:18.891Z,1665079338.891 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:02:34.244Z,1665079354.244 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:02:49.192Z,1665079369.192 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:03:04.139Z,1665079384.139 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:04:43.144Z,1665079483.144 [NAL9602](INFO): SBD MO Status=2, MOMSN=36591, MT Status=2, MTMSN=0
2022-10-06T18:04:43.144Z,1665079483.144 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-06T18:05:33.697Z,1665079533.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=36591, MT Status=2, MTMSN=0
2022-10-06T18:05:33.698Z,1665079533.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-06T18:06:41.126Z,1665079601.126 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T18:07:05.369Z,1665079625.369 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T18:07:05.370Z,1665079625.370 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:07:05.370Z,1665079625.370 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:07:05.370Z,1665079625.370 [Default:CheckIn:D] Running Loop=1
2022-10-06T18:07:05.760Z,1665079625.760 [Default:CheckIn:D] Stopped
2022-10-06T18:07:05.760Z,1665079625.760 [Default:CheckIn:E] Running Loop=1
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.145260 min 
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn:E] Stopped
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn] Stopped
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn](INFO): Running loop #6
2022-10-06T18:07:06.169Z,1665079626.169 [Default:CheckIn] Running Loop=6
2022-10-06T18:07:06.170Z,1665079626.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T18:07:06.170Z,1665079626.170 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T18:07:08.196Z,1665079628.196 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180707.00,A,3648.16758,N,12147.28063,W,0.447,0.00,061022,,,A*7F
2022-10-06T18:07:08.198Z,1665079628.198 [NAL9602](INFO): GPS fix at 20221006T180707: (36.802793, -121.788010)
2022-10-06T18:07:08.209Z,1665079628.209 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T18:07:08.209Z,1665079628.209 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T18:07:15.537Z,1665079635.537 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221006T161517/Courier0034.lzma
2022-10-06T18:07:16.539Z,1665079636.539 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0034.lzma.bak
2022-10-06T18:07:16.539Z,1665079636.539 [DataOverHttps](INFO): SBD MOMSN=17235657
2022-10-06T18:07:32.533Z,1665079652.533 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20221006T161517/Express0035.lzma
2022-10-06T18:07:33.535Z,1665079653.535 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0035.lzma.bak
2022-10-06T18:07:33.535Z,1665079653.535 [DataOverHttps](INFO): SBD MOMSN=17235660
2022-10-06T18:07:34.868Z,1665079654.868 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T18:07:34.868Z,1665079654.868 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T18:07:34.868Z,1665079654.868 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T18:07:40.498Z,1665079660.498 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T18:10:28.160Z,1665079828.160 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:10:43.108Z,1665079843.108 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:10:58.459Z,1665079858.459 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:11:14.215Z,1665079874.215 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:11:30.375Z,1665079890.375 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:11:45.323Z,1665079905.323 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:12:00.679Z,1665079920.679 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:12:16.431Z,1665079936.431 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:12:31.784Z,1665079951.784 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2022-10-06T18:12:35.431Z,1665079955.431 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T18:12:35.431Z,1665079955.431 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:12:35.431Z,1665079955.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:12:35.432Z,1665079955.432 [Default:CheckIn:D] Running Loop=1
2022-10-06T18:12:35.840Z,1665079955.840 [Default:CheckIn:D] Stopped
2022-10-06T18:12:35.840Z,1665079955.840 [Default:CheckIn:E] Running Loop=1
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.646602 min 
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn:E] Stopped
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn] Stopped
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn](INFO): Running loop #7
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn] Running Loop=7
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T18:12:36.247Z,1665079956.247 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T18:12:38.256Z,1665079958.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181237.00,A,3648.16629,N,12147.28487,W,1.730,162.57,061022,,,A*74
2022-10-06T18:12:38.268Z,1665079958.268 [NAL9602](INFO): GPS fix at 20221006T181237: (36.802771, -121.788081)
2022-10-06T18:12:38.280Z,1665079958.280 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T18:12:38.280Z,1665079958.280 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T18:12:46.149Z,1665079966.149 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221006T161517/Courier0037.lzma
2022-10-06T18:12:46.327Z,1665079966.327 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2022-10-06T18:12:47.151Z,1665079967.151 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0037.lzma.bak
2022-10-06T18:12:47.151Z,1665079967.151 [DataOverHttps](INFO): SBD MOMSN=17235742
2022-10-06T18:13:06.309Z,1665079986.309 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221006T161517/Express0038.lzma
2022-10-06T18:13:07.311Z,1665079987.311 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0038.lzma.bak
2022-10-06T18:13:07.311Z,1665079987.311 [DataOverHttps](INFO): SBD MOMSN=17235745
2022-10-06T18:13:08.641Z,1665079988.641 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T18:13:08.641Z,1665079988.641 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T18:13:08.642Z,1665079988.642 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T18:13:09.022Z,1665079989.022 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-06T18:13:09.097Z,1665079989.097 [NAL9602](ERROR): received: 
+CSQ:0

OK591, 2, 0, 0, 0

OK
2022-10-06T18:15:32.109Z,1665080132.109 [CBIT](INFO): Clearing failed state for component DropWeight
2022-10-06T18:15:32.109Z,1665080132.109 [DropWeight] No Fault, FailCount= 1
2022-10-06T18:17:28.817Z,1665080248.817 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 6.
2022-10-06T18:17:28.820Z,1665080248.820 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2022-10-06T18:17:40.538Z,1665080260.538 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-06T18:18:09.232Z,1665080289.232 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T18:18:09.232Z,1665080289.232 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:18:09.232Z,1665080289.232 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:18:09.233Z,1665080289.233 [Default:CheckIn:D] Running Loop=1
2022-10-06T18:18:09.642Z,1665080289.642 [Default:CheckIn:D] Stopped
2022-10-06T18:18:09.642Z,1665080289.642 [Default:CheckIn:E] Running Loop=1
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.209965 min 
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn:E] Stopped
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn] Stopped
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn](INFO): Running loop #8
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn] Running Loop=8
2022-10-06T18:18:10.036Z,1665080290.036 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T18:18:10.037Z,1665080290.037 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T18:18:12.052Z,1665080292.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181811.00,A,3648.15827,N,12147.27761,W,0.952,162.57,061022,,,A*76
2022-10-06T18:18:12.054Z,1665080292.054 [NAL9602](INFO): GPS fix at 20221006T181811: (36.802638, -121.787960)
2022-10-06T18:18:12.094Z,1665080292.094 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T18:18:12.094Z,1665080292.094 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T18:18:22.109Z,1665080302.109 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20221006T161517/Courier0040.lzma
2022-10-06T18:18:23.111Z,1665080303.111 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0040.lzma.bak
2022-10-06T18:18:23.111Z,1665080303.111 [DataOverHttps](INFO): SBD MOMSN=17235750
2022-10-06T18:18:40.257Z,1665080320.257 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221006T161517/Express0041.lzma
2022-10-06T18:18:41.259Z,1665080321.259 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0041.lzma.bak
2022-10-06T18:18:41.259Z,1665080321.259 [DataOverHttps](INFO): SBD MOMSN=17235753
2022-10-06T18:18:42.399Z,1665080322.399 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T18:18:42.399Z,1665080322.399 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T18:18:42.399Z,1665080322.399 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T18:18:44.418Z,1665080324.418 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-06T18:21:21.930Z,1665080481.930 [DataOverHttps](IMPORTANT): SBD MTMSN=20221006T182121
2022-10-06T18:21:29.205Z,1665080489.205 [DataOverHttps](INFO): Received command: strobe off
2022-10-06T18:21:29.286Z,1665080489.286 [CommandExec](IMPORTANT): got command strobe off
2022-10-06T18:21:29.287Z,1665080489.287 [CommandExec](IMPORTANT): Deactivating strobe
2022-10-06T18:23:43.038Z,1665080623.038 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-06T18:23:43.038Z,1665080623.038 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:23:43.038Z,1665080623.038 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:23:43.038Z,1665080623.038 [Default:CheckIn:D] Running Loop=1
2022-10-06T18:23:43.432Z,1665080623.432 [Default:CheckIn:D] Stopped
2022-10-06T18:23:43.432Z,1665080623.432 [Default:CheckIn:E] Running Loop=1
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.773136 min 
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn:E] Stopped
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn] Stopped
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:23:43.831Z,1665080623.831 [Default:CheckIn](INFO): Running loop #9
2022-10-06T18:23:43.832Z,1665080623.832 [Default:CheckIn] Running Loop=9
2022-10-06T18:23:43.832Z,1665080623.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-06T18:23:43.832Z,1665080623.832 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-06T18:23:45.843Z,1665080625.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182345.00,A,3648.16520,N,12147.28541,W,0.486,25.02,061022,,,A*4F
2022-10-06T18:23:45.845Z,1665080625.845 [NAL9602](INFO): GPS fix at 20221006T182345: (36.802753, -121.788090)
2022-10-06T18:23:45.880Z,1665080625.880 [Default:CheckIn:Read_GPS] Stopped
2022-10-06T18:23:45.880Z,1665080625.880 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-06T18:23:53.585Z,1665080633.585 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221006T161517/Courier0043.lzma
2022-10-06T18:23:54.587Z,1665080634.587 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Courier0043.lzma.bak
2022-10-06T18:23:54.587Z,1665080634.587 [DataOverHttps](INFO): SBD MOMSN=17235759
2022-10-06T18:24:10.457Z,1665080650.457 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20221006T161517/Express0044.lzma
2022-10-06T18:24:11.459Z,1665080651.459 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0044.lzma.bak
2022-10-06T18:24:11.459Z,1665080651.459 [DataOverHttps](INFO): SBD MOMSN=17235762
2022-10-06T18:24:16.547Z,1665080656.547 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-06T18:24:16.621Z,1665080656.621 [NAL9602](ERROR): received: 
+CSQ:0

OK591, 2, 0, 0, 0

OK
2022-10-06T18:24:30.805Z,1665080670.805 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20221006T161517/Express0047.lzma
2022-10-06T18:24:31.807Z,1665080671.807 [DataOverHttps](INFO): Moved sent file to Logs/20221006T161517/Express0047.lzma.bak
2022-10-06T18:24:31.807Z,1665080671.807 [DataOverHttps](INFO): SBD MOMSN=17235768
2022-10-06T18:24:33.206Z,1665080673.206 [Default:CheckIn:Read_Iridium] Stopped
2022-10-06T18:24:33.206Z,1665080673.206 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-06T18:24:33.206Z,1665080673.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-06T18:25:34.298Z,1665080734.298 [CommandExec](IMPORTANT): got command quit
2022-10-06T18:25:35.301Z,1665080735.301 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:35.301Z,1665080735.301 [CommandExec](INFO): Uninitializing the command executive.
2022-10-06T18:25:35.301Z,1665080735.301 [CommandExec](INFO): Uninitializing the command scheduler.
2022-10-06T18:25:35.302Z,1665080735.302 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.469Z,1665080735.469 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-10-06T18:25:35.469Z,1665080735.469 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-10-06T18:25:35.469Z,1665080735.469 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.470Z,1665080735.470 [NavChartDb](INFO): Join timeout helper Thread ID is 6958
2022-10-06T18:25:35.501Z,1665080735.501 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:35.502Z,1665080735.502 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.513Z,1665080735.513 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-10-06T18:25:35.513Z,1665080735.513 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.514Z,1665080735.514 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6959
2022-10-06T18:25:35.945Z,1665080735.945 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:35.946Z,1665080735.946 [WetLabsBB2FL](INFO): Powering down
2022-10-06T18:25:35.946Z,1665080735.946 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.953Z,1665080735.953 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-10-06T18:25:35.953Z,1665080735.953 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:35.954Z,1665080735.954 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6960
2022-10-06T18:25:36.241Z,1665080736.241 [CTD_Seabird](INFO): Powering down
2022-10-06T18:25:36.253Z,1665080736.253 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:36.254Z,1665080736.254 [CTD_Seabird](INFO): Powering down
2022-10-06T18:25:36.265Z,1665080736.265 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:36.273Z,1665080736.273 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-10-06T18:25:36.273Z,1665080736.273 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:36.274Z,1665080736.274 [Radio_Surface](INFO): Join timeout helper Thread ID is 6961
2022-10-06T18:25:36.545Z,1665080736.545 [Radio_Surface](INFO): Powering down
2022-10-06T18:25:36.546Z,1665080736.546 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:36.546Z,1665080736.546 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:36.553Z,1665080736.553 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-10-06T18:25:36.553Z,1665080736.553 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:36.554Z,1665080736.554 [Onboard](INFO): Join timeout helper Thread ID is 6962
2022-10-06T18:25:38.617Z,1665080738.617 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:38.618Z,1665080738.618 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:38.622Z,1665080738.622 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-10-06T18:25:38.622Z,1665080738.622 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:38.623Z,1665080738.623 [DataOverHttps](INFO): Join timeout helper Thread ID is 6963
2022-10-06T18:25:39.617Z,1665080739.617 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:39.620Z,1665080739.620 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.638Z,1665080739.638 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-10-06T18:25:39.638Z,1665080739.638 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.638Z,1665080739.638 [logger](INFO): Join timeout helper Thread ID is 6964
2022-10-06T18:25:39.673Z,1665080739.673 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:39.674Z,1665080739.674 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.678Z,1665080739.678 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-10-06T18:25:39.678Z,1665080739.678 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.678Z,1665080739.678 [CommandLine](INFO): Join timeout helper Thread ID is 6965
2022-10-06T18:25:39.701Z,1665080739.701 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:39.702Z,1665080739.702 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.718Z,1665080739.718 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-10-06T18:25:39.718Z,1665080739.718 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.718Z,1665080739.718 [CommandExec](INFO): Join timeout helper Thread ID is 6966
2022-10-06T18:25:39.719Z,1665080739.719 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-10-06T18:25:39.720Z,1665080739.720 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.720Z,1665080739.720 [controlThread](INFO): Join timeout helper Thread ID is 6967
2022-10-06T18:25:39.801Z,1665080739.801 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-06T18:25:39.802Z,1665080739.802 [controlThread](DEBUG): Uninitializing ControlThread
2022-10-06T18:25:39.802Z,1665080739.802 [AHRS_M2](INFO): Powering down
2022-10-06T18:25:39.874Z,1665080739.874 [NAL9602](INFO): Powering down
2022-10-06T18:25:39.877Z,1665080739.877 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-10-06T18:25:39.878Z,1665080739.878 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-10-06T18:25:39.878Z,1665080739.878 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-10-06T18:25:39.879Z,1665080739.879 [MissionManager](INFO): Uninitializing Mission Default
2022-10-06T18:25:39.879Z,1665080739.879 [Default] Stopped
2022-10-06T18:25:39.879Z,1665080739.879 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-06T18:25:39.879Z,1665080739.879 [Default:B.GoToSurface] Stopped
2022-10-06T18:25:39.879Z,1665080739.879 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-06T18:25:39.879Z,1665080739.879 [Default:CheckIn] Stopped
2022-10-06T18:25:39.879Z,1665080739.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-06T18:25:39.879Z,1665080739.879 [Default:CheckIn:C.Wait] Stopped
2022-10-06T18:25:39.879Z,1665080739.879 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-06T18:25:39.882Z,1665080739.882 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-10-06T18:25:39.882Z,1665080739.882 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-10-06T18:25:39.883Z,1665080739.883 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-10-06T18:25:39.883Z,1665080739.883 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-10-06T18:25:39.883Z,1665080739.883 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-10-06T18:25:39.883Z,1665080739.883 [BuoyancyServo](INFO): Powering down
2022-10-06T18:25:39.897Z,1665080739.897 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-10-06T18:25:39.897Z,1665080739.897 [ElevatorServo](INFO): Powering down
2022-10-06T18:25:39.898Z,1665080739.898 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-10-06T18:25:39.898Z,1665080739.898 [MassServo](INFO): Powering down
2022-10-06T18:25:39.899Z,1665080739.899 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-10-06T18:25:39.899Z,1665080739.899 [RudderServo](INFO): Powering down
2022-10-06T18:25:39.900Z,1665080739.900 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2022-10-06T18:25:39.900Z,1665080739.900 [ThrusterServo](INFO): Powering down
2022-10-06T18:25:39.901Z,1665080739.901 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-10-06T18:25:39.902Z,1665080739.902 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-10-06T18:25:39.902Z,1665080739.902 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-10-06T18:25:39.902Z,1665080739.902 [CBIT](DEBUG): Powering off loads.
2022-10-06T18:25:39.913Z,1665080739.913 [CBIT](DEBUG): Disabling WDT.
2022-10-06T18:25:39.925Z,1665080739.925 [CBIT](DEBUG): Opening all GF detection circuits.
2022-10-06T18:25:39.926Z,1665080739.926 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.974Z,1665080739.974 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.977Z,1665080739.977 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:39.983Z,1665080739.983 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:40.054Z,1665080740.054 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:40.057Z,1665080740.057 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:40.097Z,1665080740.097 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-06T18:25:40.167Z,1665080740.167 [logger ThreadHandler](INFO): Thread cancelled.