2022-06-27T22:27:46.196Z,1656368866.196 [Supervisor](DEBUG): Initializing supervisor.
2022-06-27T22:27:46.201Z,1656368866.201 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-06-27T22:27:46.201Z,1656368866.201 [SyncHandler](INFO): Protected caller Thread ID is 838
2022-06-27T22:27:46.202Z,1656368866.202 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-06-27T22:27:46.203Z,1656368866.203 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-06-27T22:27:46.203Z,1656368866.203 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 839
2022-06-27T22:27:46.207Z,1656368866.207 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-06-27T22:27:46.225Z,1656368866.225 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-06-27T22:27:46.226Z,1656368866.226 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-06-27T22:27:46.226Z,1656368866.226 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 840
2022-06-27T22:27:46.231Z,1656368866.231 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-06-27T22:27:46.232Z,1656368866.232 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-06-27T22:27:46.232Z,1656368866.232 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 841
2022-06-27T22:27:46.234Z,1656368866.234 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-06-27T22:27:46.235Z,1656368866.235 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-06-27T22:27:46.235Z,1656368866.235 [logger ThreadHandler](INFO): Protected caller Thread ID is 842
2022-06-27T22:27:46.239Z,1656368866.239 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-06-27T22:27:46.239Z,1656368866.239 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-06-27T22:27:46.244Z,1656368866.244 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-06-27T22:27:46.339Z,1656368866.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-06-27T22:27:46.341Z,1656368866.341 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-06-27T22:27:46.971Z,1656368866.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-06-27T22:27:46.973Z,1656368866.973 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-06-27T22:27:47.192Z,1656368867.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-06-27T22:27:47.194Z,1656368867.194 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-06-27T22:27:47.274Z,1656368867.274 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-06-27T22:27:47.396Z,1656368867.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-06-27T22:27:47.398Z,1656368867.398 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-06-27T22:27:47.479Z,1656368867.479 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-06-27T22:27:47.586Z,1656368867.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-06-27T22:27:47.587Z,1656368867.587 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-06-27T22:27:47.947Z,1656368867.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-06-27T22:27:47.949Z,1656368867.949 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-06-27T22:27:48.547Z,1656368868.547 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-06-27T22:27:48.549Z,1656368868.549 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-06-27T22:27:48.762Z,1656368868.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-06-27T22:27:48.764Z,1656368868.764 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-06-27T22:27:48.950Z,1656368868.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-06-27T22:27:48.951Z,1656368868.951 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-06-27T22:27:49.411Z,1656368869.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-06-27T22:27:49.412Z,1656368869.412 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-06-27T22:27:49.699Z,1656368869.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-06-27T22:27:50.209Z,1656368870.209 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-06-27T22:27:50.658Z,1656368870.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-06-27T22:27:50.658Z,1656368870.658 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-06-27T22:27:51.020Z,1656368871.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-06-27T22:27:51.022Z,1656368871.022 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-06-27T22:27:51.353Z,1656368871.353 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-06-27T22:27:51.355Z,1656368871.355 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2022-06-27T22:27:51.359Z,1656368871.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2022-06-27T22:27:51.442Z,1656368871.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2022-06-27T22:27:51.596Z,1656368871.596 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2022-06-27T22:27:51.704Z,1656368871.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2022-06-27T22:27:51.790Z,1656368871.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2022-06-27T22:27:51.884Z,1656368871.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2022-06-27T22:27:52.064Z,1656368872.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2022-06-27T22:27:52.325Z,1656368872.325 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-06-27T22:27:52.325Z,1656368872.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2022-06-27T22:27:52.419Z,1656368872.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2022-06-27T22:27:52.517Z,1656368872.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2022-06-27T22:27:52.656Z,1656368872.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2022-06-27T22:27:52.756Z,1656368872.756 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-06-27T22:27:52.775Z,1656368872.775 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-06-27T22:27:52.895Z,1656368872.895 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-06-27T22:27:52.896Z,1656368872.896 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-06-27T22:27:52.964Z,1656368872.964 [VerticalControl](DEBUG): Construct VerticalControl.
2022-06-27T22:27:53.024Z,1656368873.024 [VerticalControl] Loaded
2022-06-27T22:27:53.024Z,1656368873.024 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-06-27T22:27:53.027Z,1656368873.027 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-06-27T22:27:53.066Z,1656368873.066 [HorizontalControl] Loaded
2022-06-27T22:27:53.066Z,1656368873.066 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-06-27T22:27:53.069Z,1656368873.069 [SpeedControl](DEBUG): Construct SpeedControl.
2022-06-27T22:27:53.072Z,1656368873.072 [SpeedControl] Loaded
2022-06-27T22:27:53.072Z,1656368873.072 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-06-27T22:27:53.075Z,1656368873.075 [LoopControl](DEBUG): Construct LoopControl.
2022-06-27T22:27:53.075Z,1656368873.075 [LoopControl] Loaded
2022-06-27T22:27:53.075Z,1656368873.075 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-06-27T22:27:53.076Z,1656368873.076 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-06-27T22:27:53.076Z,1656368873.076 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-06-27T22:27:53.146Z,1656368873.146 [DepthRateCalculator] Loaded
2022-06-27T22:27:53.146Z,1656368873.146 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-06-27T22:27:53.151Z,1656368873.151 [PitchRateCalculator] Loaded
2022-06-27T22:27:53.151Z,1656368873.151 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-06-27T22:27:53.162Z,1656368873.162 [SpeedCalculator] Loaded
2022-06-27T22:27:53.162Z,1656368873.162 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-06-27T22:27:53.166Z,1656368873.166 [YawRateCalculator] Loaded
2022-06-27T22:27:53.166Z,1656368873.166 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-06-27T22:27:53.183Z,1656368873.183 [ElevatorOffsetCalculator] Loaded
2022-06-27T22:27:53.184Z,1656368873.184 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-06-27T22:27:53.184Z,1656368873.184 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-06-27T22:27:53.185Z,1656368873.185 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-06-27T22:27:53.227Z,1656368873.227 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-06-27T22:27:53.227Z,1656368873.227 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-06-27T22:27:53.309Z,1656368873.309 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-06-27T22:27:53.310Z,1656368873.310 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-06-27T22:27:53.668Z,1656368873.668 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-06-27T22:27:53.669Z,1656368873.669 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-06-27T22:27:53.807Z,1656368873.807 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-06-27T22:27:53.808Z,1656368873.808 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-06-27T22:27:54.531Z,1656368874.531 [AHRS_M2] Loaded
2022-06-27T22:27:54.531Z,1656368874.531 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-06-27T22:27:54.781Z,1656368874.781 [BackseatComponent] Loaded
2022-06-27T22:27:54.781Z,1656368874.781 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-06-27T22:27:54.782Z,1656368874.782 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2022-06-27T22:27:54.783Z,1656368874.783 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925
2022-06-27T22:27:54.785Z,1656368874.785 [LcmUniversalReporter] Loaded
2022-06-27T22:27:54.785Z,1656368874.785 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-06-27T22:27:56.014Z,1656368876.014 [BPC1] Loaded
2022-06-27T22:27:56.015Z,1656368876.015 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-06-27T22:27:56.158Z,1656368876.158 [DataOverHttps] Loaded
2022-06-27T22:27:56.158Z,1656368876.158 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-06-27T22:27:56.159Z,1656368876.159 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099D4E0
2022-06-27T22:27:56.159Z,1656368876.159 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926
2022-06-27T22:27:56.179Z,1656368876.179 [Depth_Keller] Loaded
2022-06-27T22:27:56.179Z,1656368876.179 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-06-27T22:27:56.184Z,1656368876.184 [DropWeight] Loaded
2022-06-27T22:27:56.184Z,1656368876.184 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-06-27T22:27:56.243Z,1656368876.243 [NAL9602] Loaded
2022-06-27T22:27:56.244Z,1656368876.244 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-06-27T22:27:56.272Z,1656368876.272 [Onboard] Loaded
2022-06-27T22:27:56.272Z,1656368876.272 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-06-27T22:27:56.273Z,1656368876.273 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CD4E0
2022-06-27T22:27:56.273Z,1656368876.273 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927
2022-06-27T22:27:56.285Z,1656368876.285 [Power24vConverter] Loaded
2022-06-27T22:27:56.285Z,1656368876.285 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-06-27T22:27:56.297Z,1656368876.297 [Radio_Surface] Loaded
2022-06-27T22:27:56.298Z,1656368876.298 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-06-27T22:27:56.299Z,1656368876.299 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FD4E0
2022-06-27T22:27:56.299Z,1656368876.299 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928
2022-06-27T22:27:56.342Z,1656368876.342 [RDI_Pathfinder] Loaded
2022-06-27T22:27:56.342Z,1656368876.342 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-06-27T22:27:56.426Z,1656368876.426 [DAT] Loaded
2022-06-27T22:27:56.426Z,1656368876.426 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-06-27T22:27:56.427Z,1656368876.427 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A2D4E0
2022-06-27T22:27:56.428Z,1656368876.428 [DAT ThreadHandler](INFO): Protected caller Thread ID is 929
2022-06-27T22:27:56.428Z,1656368876.428 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-06-27T22:27:56.429Z,1656368876.429 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-06-27T22:27:56.594Z,1656368876.594 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-06-27T22:27:56.594Z,1656368876.594 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-06-27T22:27:56.607Z,1656368876.607 [NavChart] Loaded
2022-06-27T22:27:56.608Z,1656368876.608 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-06-27T22:27:56.614Z,1656368876.614 [UniversalFixResidualReporter] Loaded
2022-06-27T22:27:56.614Z,1656368876.614 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-06-27T22:27:56.614Z,1656368876.614 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-06-27T22:27:56.616Z,1656368876.616 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-06-27T22:27:56.783Z,1656368876.783 [SBIT](DEBUG): Construct Startup Built In Test.
2022-06-27T22:27:56.792Z,1656368876.792 [SBIT] Loaded
2022-06-27T22:27:56.792Z,1656368876.792 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-06-27T22:27:56.795Z,1656368876.795 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-06-27T22:27:56.808Z,1656368876.808 [IBIT] Loaded
2022-06-27T22:27:56.808Z,1656368876.808 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-06-27T22:27:56.814Z,1656368876.814 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-06-27T22:27:56.919Z,1656368876.919 [CBIT] Loaded
2022-06-27T22:27:56.919Z,1656368876.919 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-06-27T22:27:56.919Z,1656368876.919 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-06-27T22:27:56.920Z,1656368876.920 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-06-27T22:27:57.070Z,1656368877.070 [BuoyancyServo] Loaded
2022-06-27T22:27:57.070Z,1656368877.070 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-06-27T22:27:57.091Z,1656368877.091 [ElevatorServo] Loaded
2022-06-27T22:27:57.092Z,1656368877.092 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-06-27T22:27:57.110Z,1656368877.110 [MassServo] Loaded
2022-06-27T22:27:57.111Z,1656368877.111 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-06-27T22:27:57.129Z,1656368877.129 [RudderServo] Loaded
2022-06-27T22:27:57.129Z,1656368877.129 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-06-27T22:27:57.147Z,1656368877.147 [ThrusterServo] Loaded
2022-06-27T22:27:57.147Z,1656368877.147 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-06-27T22:27:57.147Z,1656368877.147 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-06-27T22:27:57.148Z,1656368877.148 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-06-27T22:27:57.164Z,1656368877.164 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-06-27T22:27:57.164Z,1656368877.164 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-06-27T22:27:57.380Z,1656368877.380 [CTD_Seabird] Loaded
2022-06-27T22:27:57.380Z,1656368877.380 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-06-27T22:27:57.382Z,1656368877.382 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B774E0
2022-06-27T22:27:57.382Z,1656368877.382 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930
2022-06-27T22:27:57.401Z,1656368877.401 [PAR_Licor] Loaded
2022-06-27T22:27:57.402Z,1656368877.402 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-06-27T22:27:57.433Z,1656368877.433 [WetLabsBB2FL] Loaded
2022-06-27T22:27:57.433Z,1656368877.433 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-06-27T22:27:57.434Z,1656368877.434 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BA74E0
2022-06-27T22:27:57.435Z,1656368877.435 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931
2022-06-27T22:27:57.455Z,1656368877.455 [WetLabsUBAT] Loaded
2022-06-27T22:27:57.455Z,1656368877.455 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2022-06-27T22:27:57.456Z,1656368877.456 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0
2022-06-27T22:27:57.457Z,1656368877.457 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 932
2022-06-27T22:27:57.457Z,1656368877.457 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-06-27T22:27:57.463Z,1656368877.463 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-06-27T22:27:57.466Z,1656368877.466 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-06-27T22:27:57.477Z,1656368877.477 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-06-27T22:27:57.478Z,1656368877.478 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0
2022-06-27T22:27:57.478Z,1656368877.478 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 933
2022-06-27T22:27:57.482Z,1656368877.482 [Supervisor](INFO): Main Thread ID is 831
2022-06-27T22:27:57.483Z,1656368877.483 [Supervisor](DEBUG): Running supervisor.
2022-06-27T22:27:57.483Z,1656368877.483 [CommandExec ThreadHandler](INFO): Handler Thread ID is 934
2022-06-27T22:27:57.484Z,1656368877.484 [CommandExec](INFO): Initializing the command executive.
2022-06-27T22:27:57.485Z,1656368877.485 [CommandLine ThreadHandler](INFO): Handler Thread ID is 935
2022-06-27T22:27:57.487Z,1656368877.487 [controlThread ThreadHandler](INFO): Handler Thread ID is 936
2022-06-27T22:27:57.488Z,1656368877.488 [controlThread](DEBUG): Initializing ControlThread
2022-06-27T22:27:57.488Z,1656368877.488 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-06-27T22:27:57.490Z,1656368877.490 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-06-27T22:27:57.491Z,1656368877.491 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-06-27T22:27:57.491Z,1656368877.491 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-06-27T22:27:57.492Z,1656368877.492 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-06-27T22:27:57.492Z,1656368877.492 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-06-27T22:27:57.492Z,1656368877.492 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-06-27T22:27:57.493Z,1656368877.493 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-06-27T22:27:57.493Z,1656368877.493 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-06-27T22:27:57.500Z,1656368877.500 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-06-27T22:27:57.500Z,1656368877.500 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-06-27T22:27:57.501Z,1656368877.501 [SBIT](INFO): Initialize SBIT Component.
2022-06-27T22:27:57.501Z,1656368877.501 [SBIT](IMPORTANT): git: 2022-06-07-3-g3731f8b3f
2022-06-27T22:27:57.501Z,1656368877.501 [SBIT](INFO): git hash: 3731f8b3f5f07755356c125fa6a04ab4ea762347
2022-06-27T22:27:57.502Z,1656368877.502 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-06-27T22:27:57.503Z,1656368877.503 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-06-27T22:27:57.504Z,1656368877.504 [SBIT](INFO): Beginning SBIT in 43.000000 seconds.
2022-06-27T22:27:57.504Z,1656368877.504 [IBIT](INFO): Initialize IBIT Component.
2022-06-27T22:27:57.505Z,1656368877.505 [CBIT](DEBUG): Initialize CBIT Component.
2022-06-27T22:27:57.506Z,1656368877.506 [logger ThreadHandler](INFO): Handler Thread ID is 937
2022-06-27T22:27:57.517Z,1656368877.517 [CBIT](DEBUG): Initialized mux pins.
2022-06-27T22:27:57.518Z,1656368877.518 [CBIT](DEBUG): Initializing the watchdog timer.
2022-06-27T22:27:57.526Z,1656368877.526 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938
2022-06-27T22:27:57.538Z,1656368877.538 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2022-06-27T22:27:57.539Z,1656368877.539 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-06-27T22:27:57.542Z,1656368877.542 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-06-27T22:27:57.542Z,1656368877.542 [CBIT](DEBUG): Initializing heartbeat.
2022-06-27T22:27:57.550Z,1656368877.550 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2022-06-27T22:27:57.567Z,1656368877.567 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2022-06-27T22:27:57.598Z,1656368877.598 [DAT ThreadHandler](INFO): Handler Thread ID is 942
2022-06-27T22:27:57.599Z,1656368877.599 [DAT](INFO): Powering up
2022-06-27T22:27:57.599Z,1656368877.599 [DAT](DEBUG): Initializing DAT.
2022-06-27T22:27:57.606Z,1656368877.606 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 944
2022-06-27T22:27:57.607Z,1656368877.607 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-06-27T22:27:57.611Z,1656368877.611 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 946
2022-06-27T22:27:57.614Z,1656368877.614 [CBIT](DEBUG): Deactivating GF circuits.
2022-06-27T22:27:57.614Z,1656368877.614 [CBIT](DEBUG): Deactivating emergency mode.
2022-06-27T22:27:57.615Z,1656368877.615 [WetLabsBB2FL](INFO): Powering up
2022-06-27T22:27:57.616Z,1656368877.616 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 948
2022-06-27T22:27:57.618Z,1656368877.618 [WetLabsUBAT](INFO): Powering up
2022-06-27T22:27:57.619Z,1656368877.619 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 950
2022-06-27T22:27:57.628Z,1656368877.628 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-06-27T22:27:57.628Z,1656368877.628 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-06-27T22:27:57.628Z,1656368877.628 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-06-27T22:27:57.628Z,1656368877.628 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-06-27T22:27:57.629Z,1656368877.629 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-06-27T22:27:57.629Z,1656368877.629 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-06-27T22:27:57.629Z,1656368877.629 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-06-27T22:27:57.629Z,1656368877.629 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-06-27T22:27:57.649Z,1656368877.649 [CBIT](DEBUG): Backplane powered.
2022-06-27T22:27:57.658Z,1656368877.658 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-06-27T22:27:57.710Z,1656368877.710 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-06-27T22:27:57.746Z,1656368877.746 [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-06-27T22:27:57.747Z,1656368877.747 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-06-27T22:27:57.833Z,1656368877.833 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-06-27T22:27:57.838Z,1656368877.838 [Default:A.Wait](DEBUG): Construct Wait.
2022-06-27T22:27:57.840Z,1656368877.840 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-06-27T22:27:57.886Z,1656368877.886 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-06-27T22:27:57.889Z,1656368877.889 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-06-27T22:27:57.911Z,1656368877.911 [Default:E.Execute](DEBUG): Construct Execute.
2022-06-27T22:27:57.915Z,1656368877.915 [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-06-27T22:27:57.926Z,1656368877.926 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,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,LcmUniversalReporter,Reporter,LogSplitter,
2022-06-27T22:27:57.942Z,1656368877.942 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-06-27T22:27:57.974Z,1656368877.974 [Radio_Surface](INFO): Powering up
2022-06-27T22:27:58.124Z,1656368878.124 [Power24vConverter](INFO): Powering up.
2022-06-27T22:27:58.125Z,1656368878.125 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-06-27T22:27:58.183Z,1656368878.183 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:27:58.190Z,1656368878.190 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-06-27T22:27:58.191Z,1656368878.191 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:27:58.198Z,1656368878.198 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-06-27T22:27:58.199Z,1656368878.199 [MassServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:27:58.206Z,1656368878.206 [MassServo](DEBUG): Initializing MassServo.
2022-06-27T22:27:58.207Z,1656368878.207 [RudderServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:27:58.214Z,1656368878.214 [RudderServo](DEBUG): Initializing RudderServo.
2022-06-27T22:27:58.215Z,1656368878.215 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:27:58.222Z,1656368878.222 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-06-27T22:27:59.074Z,1656368879.074 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-06-27T22:27:59.074Z,1656368879.074 [RudderServo](FAULT): Rudder failed to initialize
2022-06-27T22:27:59.074Z,1656368879.074 [RudderServo] Communications Fault, FailCount= 1
2022-06-27T22:27:59.074Z,1656368879.074 [RudderServo](ERROR): Communications Fault
2022-06-27T22:27:59.174Z,1656368879.174 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-06-27T22:27:59.335Z,1656368879.335 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-06-27T22:27:59.335Z,1656368879.335 [RudderServo](INFO): Powering down
2022-06-27T22:28:00.009Z,1656368880.009 [RudderServo](DEBUG): Initializing EZServoServo.
2022-06-27T22:28:00.142Z,1656368880.142 [RudderServo](DEBUG): Initializing RudderServo.
2022-06-27T22:28:00.147Z,1656368880.147 [CBIT](INFO): Clearing failed state for component RudderServo
2022-06-27T22:28:00.147Z,1656368880.147 [RudderServo] No Fault, FailCount= 1
2022-06-27T22:28:00.226Z,1656368880.226 [WetLabsBB2FL](INFO): Powering down
2022-06-27T22:28:06.942Z,1656368886.942 [WetLabsUBAT](INFO): Powering down
2022-06-27T22:28:09.703Z,1656368889.703 [DAT](INFO): DAT read: 

2022-06-27T22:28:09.708Z,1656368889.708 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-06-27T22:28:11.214Z,1656368891.214 [DAT](INFO): DAT read: MF Frequency Band

2022-06-27T22:28:11.216Z,1656368891.216 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-06-27T22:28:11.216Z,1656368891.216 [DAT](INFO): DAT read: Jun 27 2022 22:28:04 

2022-06-27T22:28:12.223Z,1656368892.223 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-06-27T22:28:12.224Z,1656368892.224 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-06-27T22:28:12.224Z,1656368892.224 [DAT](INFO): commRate: 800
2022-06-27T22:28:14.290Z,1656368894.290 [DAT](INFO): entering command mode
2022-06-27T22:28:14.490Z,1656368894.490 [DAT](INFO): DAT read: 

2022-06-27T22:28:14.491Z,1656368894.491 [DAT](INFO): DAT read: user:1>

2022-06-27T22:28:14.491Z,1656368894.491 [DAT](INFO): setting verbose to 3
2022-06-27T22:28:14.742Z,1656368894.742 [DAT](INFO): DAT read: user:1>

2022-06-27T22:28:14.743Z,1656368894.743 [DAT](INFO): DAT read: Verbose         | 3           

2022-06-27T22:28:14.744Z,1656368894.744 [DAT](INFO): set verbose to 3
2022-06-27T22:28:14.744Z,1656368894.744 [DAT](INFO): setting DatVerbose to 27440
2022-06-27T22:28:14.996Z,1656368894.996 [DAT](INFO): DAT read: user:2>

2022-06-27T22:28:14.997Z,1656368894.997 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-06-27T22:28:14.997Z,1656368894.997 [DAT](INFO): set DatVerbose to 27440
2022-06-27T22:28:14.997Z,1656368894.997 [DAT](INFO): setting transmit power to 8
2022-06-27T22:28:15.246Z,1656368895.246 [DAT](INFO): DAT read: user:3>

2022-06-27T22:28:15.247Z,1656368895.247 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-06-27T22:28:15.247Z,1656368895.247 [DAT](INFO): set transmit power to 8
2022-06-27T22:28:15.248Z,1656368895.248 [DAT](INFO): setting local address to 9
2022-06-27T22:28:15.498Z,1656368895.498 [DAT](INFO): DAT read: user:4>

2022-06-27T22:28:15.499Z,1656368895.499 [DAT](INFO): DAT read: LocalAddr       | 9           

2022-06-27T22:28:15.499Z,1656368895.499 [DAT](INFO): set local address to 9
2022-06-27T22:28:26.275Z,1656368906.275 [NAL9602](INFO): Powering up NAL9602
2022-06-27T22:28:37.159Z,1656368917.159 [NAL9602](INFO): NAL9602 initialized
2022-06-27T22:28:41.264Z,1656368921.264 [SBIT](IMPORTANT): Beginning Startup BIT
2022-06-27T22:28:41.272Z,1656368921.272 [CBIT](IMPORTANT): Beginning ground fault scan
2022-06-27T22:28:52.199Z,1656368932.199 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.009024
CHAN A1 (24V): 0.001271
CHAN A2 (12V): -0.007666
CHAN A3 (5V): -0.003252
CHAN B0 (3.3V): 0.000388
CHAN B1 (3.15aV): -0.000246
CHAN B2 (3.15bV): 0.000143
CHAN B3 (GND): 0.001694
OPEN: -0.004273
Full Scale: +/- 1 mA
2022-06-27T22:29:35.352Z,1656368975.352 [SBIT](IMPORTANT): SBIT PASSED
2022-06-27T22:29:35.353Z,1656368975.353 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): DAT.verbosity=2 count;

2022-06-27T22:29:35.354Z,1656368975.354 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): Express none _.adinos;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): Express none _.aother;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-06-27T22:29:35.355Z,1656368975.355 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=227.556099 cubic_centimeter;

2022-06-27T22:29:35.356Z,1656368975.356 [SBIT](IMPORTANT): VerticalControl.massDefault=5.797035 millimeter;

2022-06-27T22:29:35.799Z,1656368975.799 [MissionManager](IMPORTANT): Started mission Startup
2022-06-27T22:29:35.800Z,1656368975.800 [Startup] Running Loop=1
2022-06-27T22:29:35.800Z,1656368975.800 [Startup](DEBUG): Aggregate::initialize Startup
2022-06-27T22:29:35.800Z,1656368975.800 [Startup:A.GoToSurface] Running Loop=1
2022-06-27T22:29:35.800Z,1656368975.800 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-06-27T22:29:35.800Z,1656368975.800 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-06-27T22:29:35.801Z,1656368975.801 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-06-27T22:29:35.801Z,1656368975.801 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-06-27T22:29:35.802Z,1656368975.802 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-06-27T22:29:35.802Z,1656368975.802 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-06-27T22:29:35.803Z,1656368975.803 [Startup:StartupSatComms] Running Loop=1
2022-06-27T22:29:35.803Z,1656368975.803 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-06-27T22:29:35.804Z,1656368975.804 [Startup:StartupSatComms:A] Running Loop=1
2022-06-27T22:29:36.171Z,1656368976.171 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-06-27T22:29:56.801Z,1656368996.801 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-27T22:30:33.967Z,1656369033.967 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-27T22:30:35.986Z,1656369035.986 [Startup:StartupSatComms:A](INFO): Timed out from 2022-06-27T22:29:35.8Z
2022-06-27T22:30:35.986Z,1656369035.986 [Startup:StartupSatComms:A] Stopped
2022-06-27T22:30:35.986Z,1656369035.986 [Startup:StartupSatComms:B] Running Loop=1
2022-06-27T22:30:36.387Z,1656369036.387 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-06-27T22:30:42.730Z,1656369042.730 [CommandExec](IMPORTANT): got command failComponent
2022-06-27T22:30:42.730Z,1656369042.730 [CommandExec](IMPORTANT): Failed components:
2022-06-27T22:30:42.731Z,1656369042.731 [CommandExec](IMPORTANT): No failed Components.
2022-06-27T22:30:42.888Z,1656369042.888 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004949
2022-06-27T22:30:49.222Z,1656369049.222 [CommandExec](IMPORTANT): got command failComponent
2022-06-27T22:30:49.223Z,1656369049.223 [CommandExec](IMPORTANT): Failed components:
2022-06-27T22:30:49.223Z,1656369049.223 [CommandExec](IMPORTANT): No failed Components.
2022-06-27T22:30:49.567Z,1656369049.567 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-06-27T22:30:51.978Z,1656369051.978 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220627T221448/Courier0007.lzma
2022-06-27T22:30:52.979Z,1656369052.979 [DataOverHttps](INFO): Moved sent file to Logs/20220627T221448/Courier0007.lzma.bak
2022-06-27T22:30:52.979Z,1656369052.979 [DataOverHttps](INFO): SBD MOMSN=16926805
2022-06-27T22:30:57.661Z,1656369057.661 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-06-27T22:30:57.661Z,1656369057.661 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:30:57.703Z,1656369057.703 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:30:58.115Z,1656369058.115 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:30:58.115Z,1656369058.115 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-06-27T22:31:08.948Z,1656369068.948 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220627T222746/Courier0000.lzma
2022-06-27T22:31:09.950Z,1656369069.950 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0000.lzma.bak
2022-06-27T22:31:09.951Z,1656369069.951 [DataOverHttps](INFO): SBD MOMSN=16926807
2022-06-27T22:31:28.954Z,1656369088.954 [DataOverHttps](INFO): Sending 451 bytes from file Logs/20220627T221448/Express0008.lzma
2022-06-27T22:31:29.955Z,1656369089.955 [DataOverHttps](INFO): Moved sent file to Logs/20220627T221448/Express0008.lzma.bak
2022-06-27T22:31:29.955Z,1656369089.955 [DataOverHttps](INFO): SBD MOMSN=16926810
2022-06-27T22:31:36.106Z,1656369096.106 [Startup:StartupSatComms:B](INFO): Timed out from 2022-06-27T22:30:35.0Z
2022-06-27T22:31:36.106Z,1656369096.106 [Startup:StartupSatComms:B] Stopped
2022-06-27T22:31:36.107Z,1656369096.107 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-06-27T22:31:36.107Z,1656369096.107 [Startup:StartupSatComms] Stopped
2022-06-27T22:31:36.107Z,1656369096.107 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-06-27T22:31:36.108Z,1656369096.108 [Startup](INFO): Completed Startup
2022-06-27T22:31:36.108Z,1656369096.108 [MissionManager](INFO): Startup is completed.
2022-06-27T22:31:36.108Z,1656369096.108 [MissionManager](INFO): Uninitializing Mission Startup
2022-06-27T22:31:36.108Z,1656369096.108 [Startup] Stopped
2022-06-27T22:31:36.108Z,1656369096.108 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-06-27T22:31:36.108Z,1656369096.108 [Startup:A.GoToSurface] Stopped
2022-06-27T22:31:36.108Z,1656369096.108 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-06-27T22:31:36.487Z,1656369096.487 [MissionManager](IMPORTANT): Started mission Default
2022-06-27T22:31:36.487Z,1656369096.487 [Default] Running Loop=1
2022-06-27T22:31:36.487Z,1656369096.487 [Default](DEBUG): Aggregate::initialize Default
2022-06-27T22:31:36.488Z,1656369096.488 [Default:B.GoToSurface] Running Loop=1
2022-06-27T22:31:36.488Z,1656369096.488 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-06-27T22:31:36.488Z,1656369096.488 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-06-27T22:31:36.488Z,1656369096.488 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-06-27T22:31:36.521Z,1656369096.521 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-06-27T22:31:36.521Z,1656369096.521 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-06-27T22:31:36.521Z,1656369096.521 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-06-27T22:31:36.522Z,1656369096.522 [Default:A.Wait] Running Loop=1
2022-06-27T22:31:36.522Z,1656369096.522 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-06-27T22:31:49.807Z,1656369109.807 [Default:A.Wait](INFO): Done Waiting.
2022-06-27T22:31:49.807Z,1656369109.807 [Default:A.Wait] Stopped
2022-06-27T22:31:49.807Z,1656369109.807 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T22:31:50.166Z,1656369110.166 [DataOverHttps](INFO): Sending 1040 bytes from file Logs/20220627T222746/Express0001.lzma
2022-06-27T22:31:50.269Z,1656369110.269 [Default:CheckIn] Running Loop=1
2022-06-27T22:31:50.269Z,1656369110.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T22:31:50.269Z,1656369110.269 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T22:31:50.648Z,1656369110.648 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-06-27T22:31:51.166Z,1656369111.166 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0001.lzma.bak
2022-06-27T22:31:51.167Z,1656369111.167 [DataOverHttps](INFO): SBD MOMSN=16926825
2022-06-27T22:33:40.557Z,1656369220.557 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-06-27T22:33:58.765Z,1656369238.765 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-06-27T22:33:58.765Z,1656369238.765 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:33:58.788Z,1656369238.788 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:33:59.173Z,1656369239.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:33:59.173Z,1656369239.173 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-06-27T22:34:37.921Z,1656369277.921 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-06-27T22:34:37.924Z,1656369277.924 [BPC1](INFO): Received data from all battery sticks.
2022-06-27T22:36:50.437Z,1656369410.437 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-06-27T22:31:50.3Z
2022-06-27T22:36:50.437Z,1656369410.437 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T22:36:50.437Z,1656369410.437 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T22:36:50.851Z,1656369410.851 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-06-27T22:36:58.218Z,1656369418.218 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20220627T222746/Courier0004.lzma
2022-06-27T22:36:59.217Z,1656369419.217 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0004.lzma.bak
2022-06-27T22:36:59.217Z,1656369419.217 [DataOverHttps](INFO): SBD MOMSN=16926854
2022-06-27T22:36:59.741Z,1656369419.741 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-06-27T22:36:59.741Z,1656369419.741 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:36:59.751Z,1656369419.751 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:37:00.170Z,1656369420.170 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:37:00.170Z,1656369420.170 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-06-27T22:37:15.053Z,1656369435.053 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20220627T222746/Express0005.lzma
2022-06-27T22:37:16.054Z,1656369436.054 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0005.lzma.bak
2022-06-27T22:37:16.055Z,1656369436.055 [DataOverHttps](INFO): SBD MOMSN=16926856
2022-06-27T22:37:17.532Z,1656369437.532 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T22:37:17.532Z,1656369437.532 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T22:37:17.533Z,1656369437.533 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T22:38:39.511Z,1656369519.511 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-06-27T22:38:39.511Z,1656369519.511 [NAL9602] Data Fault, FailCount= 1
2022-06-27T22:38:39.511Z,1656369519.511 [NAL9602](ERROR): Data Fault
2022-06-27T22:38:39.574Z,1656369519.574 [CBIT](ERROR): Data Fault in component: NAL9602
2022-06-27T22:38:39.914Z,1656369519.914 [NAL9602](INFO): Powering down
2022-06-27T22:38:40.754Z,1656369520.754 [CBIT](INFO): Clearing failed state for component NAL9602
2022-06-27T22:38:40.754Z,1656369520.754 [NAL9602] No Fault, FailCount= 1
2022-06-27T22:39:10.215Z,1656369550.215 [NAL9602](INFO): Powering up NAL9602
2022-06-27T22:39:21.127Z,1656369561.127 [NAL9602](INFO): NAL9602 initialized
2022-06-27T22:40:00.748Z,1656369600.748 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-06-27T22:40:00.748Z,1656369600.748 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:40:00.759Z,1656369600.759 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:40:01.183Z,1656369601.183 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:40:01.183Z,1656369601.183 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-06-27T22:40:58.235Z,1656369658.235 [DataOverHttps](IMPORTANT): SBD MTMSN=20220627T224057
2022-06-27T22:41:05.781Z,1656369665.781 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-06-27T22:41:05.907Z,1656369665.907 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-06-27T22:41:05.908Z,1656369665.908 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-06-27T22:41:05.986Z,1656369665.986 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-06-27T22:41:05.989Z,1656369665.989 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-06-27T22:41:05.992Z,1656369665.992 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-06-27T22:41:05.995Z,1656369665.995 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-06-27T22:41:05.998Z,1656369665.998 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-06-27T22:41:06.001Z,1656369666.001 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-06-27T22:41:06.003Z,1656369666.003 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-06-27T22:41:06.006Z,1656369666.006 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-06-27T22:41:06.010Z,1656369666.010 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-06-27T22:41:06.012Z,1656369666.012 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-06-27T22:41:06.040Z,1656369666.040 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-06-27T22:41:06.044Z,1656369666.044 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-06-27T22:41:06.055Z,1656369666.055 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-06-27T22:41:06.059Z,1656369666.059 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-06-27T22:41:06.059Z,1656369666.059 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-06-27T22:41:06.457Z,1656369666.457 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-06-27T22:41:06.460Z,1656369666.460 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-06-27T22:41:06.463Z,1656369666.463 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-06-27T22:41:06.466Z,1656369666.466 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-06-27T22:41:06.468Z,1656369666.468 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-06-27T22:41:06.471Z,1656369666.471 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-06-27T22:41:06.474Z,1656369666.474 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-06-27T22:41:06.476Z,1656369666.476 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-06-27T22:41:06.479Z,1656369666.479 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-06-27T22:41:06.482Z,1656369666.482 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-06-27T22:41:06.485Z,1656369666.485 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-06-27T22:41:06.488Z,1656369666.488 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-06-27T22:41:06.518Z,1656369666.518 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-06-27T22:41:06.521Z,1656369666.521 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-06-27T22:41:06.523Z,1656369666.523 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-06-27T22:41:06.527Z,1656369666.527 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-06-27T22:41:06.539Z,1656369666.539 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-06-27T22:41:06.542Z,1656369666.542 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-06-27T22:41:06.556Z,1656369666.556 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-06-27T22:41:06.564Z,1656369666.564 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-06-27T22:41:06.568Z,1656369666.568 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 1 bool
2022-06-27T22:41:06.583Z,1656369666.583 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-06-27T22:41:06.587Z,1656369666.587 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-06-27T22:41:06.624Z,1656369666.624 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-06-27T22:41:06.632Z,1656369666.632 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-06-27T22:41:06.648Z,1656369666.648 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-06-27T22:41:06.655Z,1656369666.655 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-06-27T22:41:06.670Z,1656369666.670 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-06-27T22:41:06.677Z,1656369666.677 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-06-27T22:41:06.680Z,1656369666.680 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-06-27T22:41:06.692Z,1656369666.692 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-06-27T22:41:06.696Z,1656369666.696 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-06-27T22:41:06.707Z,1656369666.707 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-06-27T22:41:06.711Z,1656369666.711 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-06-27T22:41:06.722Z,1656369666.722 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-06-27T22:41:06.728Z,1656369666.728 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-06-27T22:41:06.740Z,1656369666.740 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-06-27T22:41:06.747Z,1656369666.747 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-06-27T22:41:06.754Z,1656369666.754 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-06-27T22:41:06.758Z,1656369666.758 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-06-27T22:41:06.771Z,1656369666.771 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-06-27T22:41:06.775Z,1656369666.775 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-06-27T22:41:06.794Z,1656369666.794 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-06-27T22:41:06.798Z,1656369666.798 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-06-27T22:41:06.809Z,1656369666.809 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-06-27T22:41:06.817Z,1656369666.817 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-06-27T22:41:06.820Z,1656369666.820 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-06-27T22:41:06.828Z,1656369666.828 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-06-27T22:41:06.838Z,1656369666.838 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-06-27T22:41:06.842Z,1656369666.842 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-06-27T22:41:06.849Z,1656369666.849 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-06-27T22:41:06.866Z,1656369666.866 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-06-27T22:41:06.891Z,1656369666.891 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-06-27T22:41:06.908Z,1656369666.908 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-06-27T22:41:06.920Z,1656369666.920 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-06-27T22:41:06.927Z,1656369666.927 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-06-27T22:41:06.931Z,1656369666.931 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-06-27T22:41:06.946Z,1656369666.946 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-06-27T22:41:06.955Z,1656369666.955 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-06-27T22:41:06.962Z,1656369666.962 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-06-27T22:41:06.965Z,1656369666.965 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-06-27T22:41:06.968Z,1656369666.968 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-06-27T22:41:06.980Z,1656369666.980 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-06-27T22:41:06.987Z,1656369666.987 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-06-27T22:41:06.994Z,1656369666.994 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-06-27T22:41:07.110Z,1656369667.110 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-06-27T22:41:07.136Z,1656369667.136 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-06-27T22:41:07.174Z,1656369667.174 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-06-27T22:41:07.190Z,1656369667.190 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-06-27T22:41:07.216Z,1656369667.216 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-06-27T22:41:07.250Z,1656369667.250 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-06-27T22:41:07.277Z,1656369667.277 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-06-27T22:41:07.306Z,1656369667.306 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-06-27T22:41:07.332Z,1656369667.332 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-06-27T22:41:07.578Z,1656369667.578 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-06-27T22:41:07.583Z,1656369667.583 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-06-27T22:41:07.594Z,1656369667.594 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-06-27T22:41:07.601Z,1656369667.601 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-06-27T22:41:07.604Z,1656369667.604 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-06-27T22:41:07.611Z,1656369667.611 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-06-27T22:41:07.626Z,1656369667.626 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-06-27T22:41:07.634Z,1656369667.634 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-06-27T22:41:07.640Z,1656369667.640 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-06-27T22:41:07.644Z,1656369667.644 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-06-27T22:41:07.651Z,1656369667.651 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-06-27T22:41:07.655Z,1656369667.655 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-06-27T22:41:07.671Z,1656369667.671 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-06-27T22:41:07.678Z,1656369667.678 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-06-27T22:41:07.710Z,1656369667.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-06-27T22:41:07.726Z,1656369667.726 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-06-27T22:41:07.734Z,1656369667.734 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-06-27T22:41:07.751Z,1656369667.751 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-06-27T22:41:07.760Z,1656369667.760 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-06-27T22:41:07.763Z,1656369667.763 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-06-27T22:41:07.779Z,1656369667.779 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-06-27T22:41:07.788Z,1656369667.788 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-06-27T22:41:07.802Z,1656369667.802 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-06-27T22:41:07.878Z,1656369667.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-06-27T22:41:07.923Z,1656369667.923 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-06-27T22:41:07.969Z,1656369667.969 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-06-27T22:41:07.971Z,1656369667.971 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-06-27T22:41:07.972Z,1656369667.972 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-06-27T22:41:07.978Z,1656369667.978 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-06-27T22:41:07.980Z,1656369667.980 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-06-27T22:41:07.986Z,1656369667.986 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-06-27T22:41:07.988Z,1656369667.988 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-06-27T22:41:07.998Z,1656369667.998 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-06-27T22:41:08.023Z,1656369668.023 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-06-27T22:41:08.037Z,1656369668.037 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-06-27T22:41:08.088Z,1656369668.088 [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-06-27T22:41:08.100Z,1656369668.100 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-06-27T22:41:08.281Z,1656369668.281 [Default] Stopped
2022-06-27T22:41:08.281Z,1656369668.281 [Default](DEBUG): Aggregate::uninitialize Default
2022-06-27T22:41:08.282Z,1656369668.282 [Default:B.GoToSurface] Stopped
2022-06-27T22:41:08.282Z,1656369668.282 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-06-27T22:41:08.282Z,1656369668.282 [Default:CheckIn] Stopped
2022-06-27T22:41:08.282Z,1656369668.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T22:41:08.282Z,1656369668.282 [Default:CheckIn:C.Wait] Stopped
2022-06-27T22:41:08.282Z,1656369668.282 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T22:41:08.282Z,1656369668.282 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-06-27T22:41:08.282Z,1656369668.282 [ballast_and_trim] Running Loop=1
2022-06-27T22:41:08.282Z,1656369668.282 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:A] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:B] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:C] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:D] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:E] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:F] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-06-27T22:41:08.283Z,1656369668.283 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-06-27T22:41:08.284Z,1656369668.284 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-06-27T22:41:08.290Z,1656369668.290 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-06-27T22:41:08.290Z,1656369668.290 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-06-27T22:41:08.290Z,1656369668.290 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-06-27T22:41:08.290Z,1656369668.290 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-06-27T22:41:08.290Z,1656369668.290 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-06-27T22:41:08.291Z,1656369668.291 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-06-27T22:41:08.291Z,1656369668.291 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-06-27T22:41:08.291Z,1656369668.291 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-06-27T22:41:08.297Z,1656369668.297 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-06-27T22:41:08.297Z,1656369668.297 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-06-27T22:41:08.297Z,1656369668.297 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-06-27T22:41:08.297Z,1656369668.297 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-06-27T22:41:08.299Z,1656369668.299 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-06-27T22:41:08.299Z,1656369668.299 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-06-27T22:41:08.299Z,1656369668.299 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-06-27T22:41:08.299Z,1656369668.299 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-06-27T22:41:08.300Z,1656369668.300 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-06-27T22:41:08.300Z,1656369668.300 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-06-27T22:41:08.300Z,1656369668.300 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-06-27T22:41:08.300Z,1656369668.300 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-06-27T22:41:08.307Z,1656369668.307 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-06-27T22:41:08.307Z,1656369668.307 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-06-27T22:41:08.313Z,1656369668.313 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-06-27T22:41:08.313Z,1656369668.313 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-06-27T22:41:08.315Z,1656369668.315 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-06-27T22:41:08.315Z,1656369668.315 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-06-27T22:41:08.315Z,1656369668.315 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-06-27T22:41:08.315Z,1656369668.315 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-06-27T22:41:08.316Z,1656369668.316 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-06-27T22:41:08.321Z,1656369668.321 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-06-27T22:41:08.321Z,1656369668.321 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-06-27T22:41:08.321Z,1656369668.321 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-06-27T22:41:08.322Z,1656369668.322 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-06-27T22:41:08.322Z,1656369668.322 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-06-27T22:41:08.322Z,1656369668.322 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-06-27T22:41:08.322Z,1656369668.322 [ballast_and_trim:Science] Running Loop=1
2022-06-27T22:41:08.323Z,1656369668.323 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-06-27T22:41:08.323Z,1656369668.323 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-06-27T22:41:08.323Z,1656369668.323 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-06-27T22:41:08.323Z,1656369668.323 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-06-27T22:41:08.323Z,1656369668.323 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-06-27T22:41:08.324Z,1656369668.324 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-06-27T22:41:08.329Z,1656369668.329 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-06-27T22:41:08.330Z,1656369668.330 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-06-27T22:41:08.332Z,1656369668.332 [ballast_and_trim:Science:Read_Oil] Stopped
2022-06-27T22:41:08.332Z,1656369668.332 [ballast_and_trim:Science:F] Running Loop=1
2022-06-27T22:41:08.334Z,1656369668.334 [ballast_and_trim:Science:F](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.average_bioluminescence
2022-06-27T22:41:08.334Z,1656369668.334 [ballast_and_trim:Science:E] Running Loop=1
2022-06-27T22:41:08.335Z,1656369668.335 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-06-27T22:41:08.335Z,1656369668.335 [ballast_and_trim:Science:D] Stopped
2022-06-27T22:41:08.335Z,1656369668.335 [ballast_and_trim:Science:C] Running Loop=1
2022-06-27T22:41:08.335Z,1656369668.335 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-06-27T22:41:08.336Z,1656369668.336 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-06-27T22:41:08.336Z,1656369668.336 [ballast_and_trim:Science:B] Running Loop=1
2022-06-27T22:41:08.337Z,1656369668.337 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-06-27T22:41:08.338Z,1656369668.338 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-06-27T22:41:08.338Z,1656369668.338 [ballast_and_trim:Science:A] Stopped
2022-06-27T22:41:08.671Z,1656369668.671 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-06-27T22:41:08.671Z,1656369668.671 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-06-27T22:41:08.671Z,1656369668.671 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-06-27T22:41:08.672Z,1656369668.672 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-06-27T22:41:08.672Z,1656369668.672 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-06-27T22:41:08.672Z,1656369668.672 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-06-27T22:41:08.672Z,1656369668.672 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-06-27T22:41:08.672Z,1656369668.672 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-06-27T22:41:08.678Z,1656369668.678 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-06-27T22:41:08.679Z,1656369668.679 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-06-27T22:41:08.680Z,1656369668.680 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-06-27T22:41:08.680Z,1656369668.680 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-06-27T22:41:08.680Z,1656369668.680 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-06-27T22:41:08.680Z,1656369668.680 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-06-27T22:41:08.680Z,1656369668.680 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-06-27T22:41:08.685Z,1656369668.685 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-06-27T22:41:08.685Z,1656369668.685 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-06-27T22:41:08.730Z,1656369668.730 [WetLabsBB2FL](INFO): Powering up
2022-06-27T22:41:08.791Z,1656369668.791 [WetLabsUBAT](INFO): Powering up
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-06-27T22:41:09.088Z,1656369669.088 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-06-27T22:41:09.481Z,1656369669.481 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-06-27T22:41:09.481Z,1656369669.481 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-06-27T22:41:09.481Z,1656369669.481 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T22:41:09.481Z,1656369669.481 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-06-27T22:41:09.482Z,1656369669.482 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-06-27T22:41:09.873Z,1656369669.873 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-06-27T22:41:09.873Z,1656369669.873 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-06-27T22:41:09.873Z,1656369669.873 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-06-27T22:41:09.874Z,1656369669.874 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-06-27T22:41:09.874Z,1656369669.874 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-06-27T22:41:11.394Z,1656369671.394 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-06-27T22:41:13.403Z,1656369673.403 [CTD_Seabird](ERROR): Salinity reading out of range: 4.179745 psu
2022-06-27T22:41:18.974Z,1656369678.974 [WetLabsUBAT](FAULT): UBAT flow rate is below the specified threshold of 0.05 l/s.
2022-06-27T22:43:01.764Z,1656369781.764 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-06-27T22:43:01.764Z,1656369781.764 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:43:01.905Z,1656369781.905 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:43:02.184Z,1656369782.184 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:43:02.184Z,1656369782.184 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-06-27T22:43:16.209Z,1656369796.209 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T22:43:23.237Z,1656369803.237 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239151
2022-06-27T22:43:58.481Z,1656369838.481 [Radio_Surface](INFO): Powering down
2022-06-27T22:44:26.513Z,1656369866.513 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T22:44:27.517Z,1656369867.517 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-06-27T22:45:15.530Z,1656369915.530 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-06-27T22:45:15.531Z,1656369915.531 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-06-27T22:45:15.531Z,1656369915.531 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-06-27T22:45:15.531Z,1656369915.531 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-06-27T22:45:15.531Z,1656369915.531 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-06-27T22:45:15.531Z,1656369915.531 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-06-27T22:45:15.532Z,1656369915.532 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-06-27T22:45:15.533Z,1656369915.533 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-06-27T22:45:15.901Z,1656369915.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.037325 m 
2022-06-27T22:45:15.901Z,1656369915.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-06-27T22:45:15.901Z,1656369915.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-06-27T22:45:15.901Z,1656369915.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-06-27T22:45:15.901Z,1656369915.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-06-27T22:45:15.902Z,1656369915.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-06-27T22:45:17.977Z,1656369917.977 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-06-27T22:46:02.753Z,1656369962.753 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-06-27T22:46:02.753Z,1656369962.753 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:46:02.807Z,1656369962.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:46:03.230Z,1656369963.230 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:46:03.230Z,1656369963.230 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-06-27T22:49:03.774Z,1656370143.774 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-06-27T22:49:03.774Z,1656370143.774 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:49:03.846Z,1656370143.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:49:04.192Z,1656370144.192 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:49:04.192Z,1656370144.192 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-06-27T22:49:22.322Z,1656370162.322 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-06-27T22:49:22.322Z,1656370162.322 [NAL9602] Data Fault, FailCount= 2
2022-06-27T22:49:22.322Z,1656370162.322 [NAL9602](ERROR): Data Fault
2022-06-27T22:49:22.424Z,1656370162.424 [CBIT](ERROR): Data Fault in component: NAL9602
2022-06-27T22:49:22.737Z,1656370162.737 [NAL9602](INFO): Powering down
2022-06-27T22:49:23.596Z,1656370163.596 [CBIT](INFO): Clearing failed state for component NAL9602
2022-06-27T22:49:23.596Z,1656370163.596 [NAL9602] No Fault, FailCount= 2
2022-06-27T22:49:53.037Z,1656370193.037 [NAL9602](INFO): Powering up NAL9602
2022-06-27T22:50:03.946Z,1656370203.946 [NAL9602](INFO): NAL9602 initialized
2022-06-27T22:50:30.277Z,1656370230.277 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2022-06-27T22:51:05.361Z,1656370265.361 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-06-27T22:52:04.802Z,1656370324.802 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2022-06-27T22:52:04.802Z,1656370324.802 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:52:04.851Z,1656370324.851 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:52:05.216Z,1656370325.216 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:52:05.216Z,1656370325.216 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2022-06-27T22:54:20.486Z,1656370460.486 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-06-27T22:55:05.762Z,1656370505.762 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2022-06-27T22:55:05.762Z,1656370505.762 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:55:05.943Z,1656370505.943 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:55:06.250Z,1656370506.250 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:55:06.250Z,1656370506.250 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2022-06-27T22:55:16.656Z,1656370516.656 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-06-27T22:55:16.656Z,1656370516.656 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-06-27T22:55:16.656Z,1656370516.656 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T22:55:16.657Z,1656370516.657 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-06-27T22:55:17.060Z,1656370517.060 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 7.254210 m 
2022-06-27T22:55:17.060Z,1656370517.060 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-06-27T22:55:17.060Z,1656370517.060 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-06-27T22:55:17.060Z,1656370517.060 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-06-27T22:58:06.776Z,1656370686.776 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2022-06-27T22:58:06.776Z,1656370686.776 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T22:58:06.825Z,1656370686.825 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T22:58:07.173Z,1656370687.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T22:58:07.173Z,1656370687.173 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2022-06-27T23:00:05.519Z,1656370805.519 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-06-27T23:00:05.519Z,1656370805.519 [NAL9602] Data Fault, FailCount= 3
2022-06-27T23:00:05.519Z,1656370805.519 [NAL9602](ERROR): Data Fault
2022-06-27T23:00:05.591Z,1656370805.591 [CBIT](ERROR): Data Fault in component: NAL9602
2022-06-27T23:00:05.928Z,1656370805.928 [NAL9602](INFO): Powering down
2022-06-27T23:00:06.818Z,1656370806.818 [CBIT](INFO): Clearing failed state for component NAL9602
2022-06-27T23:00:06.818Z,1656370806.818 [NAL9602] No Fault, FailCount= 3
2022-06-27T23:00:36.232Z,1656370836.232 [NAL9602](INFO): Powering up NAL9602
2022-06-27T23:00:47.131Z,1656370847.131 [NAL9602](INFO): NAL9602 initialized
2022-06-27T23:01:07.745Z,1656370867.745 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2022-06-27T23:01:07.745Z,1656370867.745 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:01:07.833Z,1656370867.833 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:01:08.196Z,1656370868.196 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:01:08.196Z,1656370868.196 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2022-06-27T23:03:31.186Z,1656371011.186 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-06-27T23:04:08.750Z,1656371048.750 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2022-06-27T23:04:08.750Z,1656371048.750 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:04:08.766Z,1656371048.766 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:04:09.323Z,1656371049.323 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:04:09.323Z,1656371049.323 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2022-06-27T23:05:48.152Z,1656371148.152 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-06-27T23:07:09.755Z,1656371229.755 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2022-06-27T23:07:09.755Z,1656371229.755 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:07:09.772Z,1656371229.772 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:07:10.228Z,1656371230.228 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:07:10.228Z,1656371230.228 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2022-06-27T23:09:45.537Z,1656371385.537 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-06-27T23:10:10.786Z,1656371410.786 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2022-06-27T23:10:10.786Z,1656371410.786 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:10:10.950Z,1656371410.950 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:10:11.162Z,1656371411.162 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:10:11.162Z,1656371411.162 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2022-06-27T23:10:48.718Z,1656371448.718 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-06-27T23:10:48.718Z,1656371448.718 [NAL9602] Data Fault, FailCount= 4
2022-06-27T23:10:48.718Z,1656371448.718 [NAL9602](ERROR): Data Fault
2022-06-27T23:10:48.802Z,1656371448.802 [CBIT](ERROR): Data Fault in component: NAL9602
2022-06-27T23:10:49.116Z,1656371449.116 [NAL9602](INFO): Powering down
2022-06-27T23:10:49.986Z,1656371449.986 [CBIT](INFO): Clearing failed state for component NAL9602
2022-06-27T23:10:49.986Z,1656371449.986 [NAL9602] No Fault, FailCount= 4
2022-06-27T23:11:19.411Z,1656371479.411 [NAL9602](INFO): Powering up NAL9602
2022-06-27T23:11:30.331Z,1656371490.331 [NAL9602](INFO): NAL9602 initialized
2022-06-27T23:12:01.482Z,1656371521.482 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-06-27T23:12:26.926Z,1656371546.926 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 17.16 minutes.
2022-06-27T23:12:26.927Z,1656371546.927 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 217.756135 +/- 14.999489 cc (conf. level 99.90%, sigma: 23.314286 cc).
2022-06-27T23:12:26.927Z,1656371546.927 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 5.941978 +/- 0.220749 mm (conf. level 99.90%, sigma: 0.343118 mm).
2022-06-27T23:12:26.928Z,1656371546.928 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 217.756135 cc buoyancy neutral and 5.941978 mm mass default
2022-06-27T23:12:26.952Z,1656371546.952 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-06-27T23:12:26.954Z,1656371546.954 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.verbosity=2 count;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express none _.adinos;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express none _.aother;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-06-27T23:12:26.955Z,1656371546.955 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=217.756135 cubic_centimeter;

2022-06-27T23:12:26.956Z,1656371546.956 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=5.941978 millimeter;

2022-06-27T23:12:26.956Z,1656371546.956 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-06-27T23:12:26.956Z,1656371546.956 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-06-27T23:12:26.961Z,1656371546.961 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-06-27T23:12:26.962Z,1656371546.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-06-27T23:12:26.962Z,1656371546.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-06-27T23:12:26.962Z,1656371546.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-06-27T23:12:26.962Z,1656371546.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-06-27T23:12:26.962Z,1656371546.962 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-06-27T23:12:26.963Z,1656371546.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-06-27T23:12:27.321Z,1656371547.321 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-06-27T23:12:27.321Z,1656371547.321 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-06-27T23:12:27.321Z,1656371547.321 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-06-27T23:12:27.321Z,1656371547.321 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2022-06-27T23:12:27.322Z,1656371547.322 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-06-27T23:12:27.322Z,1656371547.322 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-06-27T23:12:27.322Z,1656371547.322 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2022-06-27T23:12:27.322Z,1656371547.322 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-06-27T23:12:27.322Z,1656371547.322 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2022-06-27T23:12:27.772Z,1656371547.772 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2022-06-27T23:12:27.772Z,1656371547.772 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-06-27T23:12:27.772Z,1656371547.772 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2022-06-27T23:12:27.772Z,1656371547.772 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up] Running Loop=1
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2022-06-27T23:12:27.785Z,1656371547.785 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:12:28.136Z,1656371548.136 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-06-27T23:13:09.751Z,1656371589.751 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2022-06-27T23:13:09.751Z,1656371589.751 [RDI_Pathfinder] Communications Fault, FailCount= 1
2022-06-27T23:13:09.751Z,1656371589.751 [RDI_Pathfinder](ERROR): Communications Fault
2022-06-27T23:13:09.818Z,1656371589.818 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2022-06-27T23:13:10.197Z,1656371590.197 [RDI_Pathfinder](INFO): Powering down
2022-06-27T23:13:11.031Z,1656371591.031 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2022-06-27T23:13:11.031Z,1656371591.031 [RDI_Pathfinder] No Fault, FailCount= 1
2022-06-27T23:13:11.350Z,1656371591.350 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-06-27T23:13:11.766Z,1656371591.766 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2022-06-27T23:13:11.766Z,1656371591.766 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:13:11.813Z,1656371591.813 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:13:12.197Z,1656371592.197 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:13:12.197Z,1656371592.197 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2022-06-27T23:14:16.481Z,1656371656.481 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-06-27T23:14:32.975Z,1656371672.975 [ballast_and_trim:Float_Up] Stopped
2022-06-27T23:14:32.976Z,1656371672.976 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2022-06-27T23:14:32.976Z,1656371672.976 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2022-06-27T23:14:32.976Z,1656371672.976 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-06-27T23:14:32.976Z,1656371672.976 [ballast_and_trim:Float_Up:B.Wait] Stopped
2022-06-27T23:14:32.976Z,1656371672.976 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:14:32.979Z,1656371672.979 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-06-27T23:14:32.979Z,1656371672.979 [MissionManager](INFO): ballast_and_trim is completed.
2022-06-27T23:14:32.979Z,1656371672.979 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-06-27T23:14:32.979Z,1656371672.979 [ballast_and_trim] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:B] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:C] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:E] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:F] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-06-27T23:14:32.980Z,1656371672.980 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-06-27T23:14:33.073Z,1656371673.073 [WetLabsBB2FL](INFO): Powering down
2022-06-27T23:14:33.367Z,1656371673.367 [MissionManager](IMPORTANT): Started mission Default
2022-06-27T23:14:33.367Z,1656371673.367 [Default] Running Loop=1
2022-06-27T23:14:33.367Z,1656371673.367 [Default](DEBUG): Aggregate::initialize Default
2022-06-27T23:14:33.367Z,1656371673.367 [Default:B.GoToSurface] Running Loop=1
2022-06-27T23:14:33.367Z,1656371673.367 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-06-27T23:14:33.368Z,1656371673.368 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-06-27T23:14:33.368Z,1656371673.368 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-06-27T23:14:33.368Z,1656371673.368 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-06-27T23:14:33.369Z,1656371673.369 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-06-27T23:14:33.369Z,1656371673.369 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-06-27T23:14:33.369Z,1656371673.369 [Default:A.Wait] Running Loop=1
2022-06-27T23:14:33.369Z,1656371673.369 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:14:33.381Z,1656371673.381 [WetLabsUBAT](INFO): Powering down
2022-06-27T23:14:33.609Z,1656371673.609 [Radio_Surface](INFO): Powering up
2022-06-27T23:14:39.006Z,1656371679.006 [DataOverHttps](INFO): Radio surface powered ON.
2022-06-27T23:14:46.691Z,1656371686.691 [Default:A.Wait](INFO): Done Waiting.
2022-06-27T23:14:46.691Z,1656371686.691 [Default:A.Wait] Stopped
2022-06-27T23:14:46.691Z,1656371686.691 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:14:47.112Z,1656371687.112 [Default:CheckIn] Running Loop=1
2022-06-27T23:14:47.113Z,1656371687.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:14:47.113Z,1656371687.113 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:15:09.125Z,1656371709.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T23:15:44.265Z,1656371744.265 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T23:16:12.743Z,1656371772.743 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2022-06-27T23:16:12.743Z,1656371772.743 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-27T23:16:12.792Z,1656371772.792 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-27T23:16:13.218Z,1656371773.218 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-27T23:16:13.218Z,1656371773.218 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2022-06-27T23:16:19.421Z,1656371779.421 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T23:16:54.561Z,1656371814.561 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T23:17:29.729Z,1656371849.729 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-27T23:18:02.365Z,1656371882.365 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003005
2022-06-27T23:18:07.898Z,1656371887.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231806.00,A,3648.14875,N,12147.28817,W,0.214,222.89,270622,,,A*76
2022-06-27T23:18:07.902Z,1656371887.902 [NAL9602](INFO): GPS fix at 20220627T231806: (36.802479, -121.788136)
2022-06-27T23:18:07.959Z,1656371887.959 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:18:07.960Z,1656371887.960 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:18:17.905Z,1656371897.905 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20220627T222746/Courier0007.lzma
2022-06-27T23:18:18.907Z,1656371898.907 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0007.lzma.bak
2022-06-27T23:18:18.907Z,1656371898.907 [DataOverHttps](INFO): SBD MOMSN=16927090
2022-06-27T23:18:40.686Z,1656371920.686 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-27T23:18:44.584Z,1656371924.584 [DataOverHttps](INFO): Sending 1520 bytes from file Logs/20220627T222746/Express0008.lzma
2022-06-27T23:18:49.599Z,1656371929.599 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0008.lzma.bak
2022-06-27T23:18:49.599Z,1656371929.599 [DataOverHttps](INFO): SBD MOMSN=16927093
2022-06-27T23:18:50.827Z,1656371930.827 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:18:50.828Z,1656371930.828 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:18:50.828Z,1656371930.828 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:23:51.382Z,1656372231.382 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:23:51.382Z,1656372231.382 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:23:51.382Z,1656372231.382 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:23:51.382Z,1656372231.382 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:23:51.800Z,1656372231.800 [Default:CheckIn:D] Stopped
2022-06-27T23:23:51.800Z,1656372231.800 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:23:52.185Z,1656372232.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.307207 min 
2022-06-27T23:23:52.185Z,1656372232.185 [Default:CheckIn:E] Stopped
2022-06-27T23:23:52.185Z,1656372232.185 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:23:52.185Z,1656372232.185 [Default:CheckIn] Stopped
2022-06-27T23:23:52.185Z,1656372232.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:23:52.186Z,1656372232.186 [Default:CheckIn](INFO): Running loop #2
2022-06-27T23:23:52.186Z,1656372232.186 [Default:CheckIn] Running Loop=2
2022-06-27T23:23:52.186Z,1656372232.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:23:52.186Z,1656372232.186 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:23:54.190Z,1656372234.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232352.00,A,3648.15785,N,12147.28416,W,0.058,109.54,270622,,,A*73
2022-06-27T23:23:54.192Z,1656372234.192 [NAL9602](INFO): GPS fix at 20220627T232352: (36.802631, -121.788069)
2022-06-27T23:23:54.224Z,1656372234.224 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:23:54.224Z,1656372234.224 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:24:06.384Z,1656372246.384 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220627T222746/Courier0010.lzma
2022-06-27T23:24:07.386Z,1656372247.386 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0010.lzma.bak
2022-06-27T23:24:07.387Z,1656372247.387 [DataOverHttps](INFO): SBD MOMSN=16927182
2022-06-27T23:24:27.052Z,1656372267.052 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20220627T222746/Express0012.lzma
2022-06-27T23:24:28.055Z,1656372268.055 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0012.lzma.bak
2022-06-27T23:24:28.055Z,1656372268.055 [DataOverHttps](INFO): SBD MOMSN=16927186
2022-06-27T23:24:29.462Z,1656372269.462 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:24:29.462Z,1656372269.462 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:24:29.462Z,1656372269.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:27:35.379Z,1656372455.379 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-06-27T23:27:43.387Z,1656372463.387 [NAL9602](INFO): SBD MO Status=0, MOMSN=19345, MT Status=0, MTMSN=0
2022-06-27T23:27:43.387Z,1656372463.387 [NAL9602](INFO): No messages in MT queue
2022-06-27T23:28:14.090Z,1656372494.090 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-27T23:29:30.052Z,1656372570.052 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:29:30.052Z,1656372570.052 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:29:30.052Z,1656372570.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:29:30.052Z,1656372570.052 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:29:30.456Z,1656372570.456 [Default:CheckIn:D] Stopped
2022-06-27T23:29:30.456Z,1656372570.456 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:29:30.877Z,1656372570.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.951478 min 
2022-06-27T23:29:30.877Z,1656372570.877 [Default:CheckIn:E] Stopped
2022-06-27T23:29:30.877Z,1656372570.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:29:30.877Z,1656372570.877 [Default:CheckIn] Stopped
2022-06-27T23:29:30.878Z,1656372570.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:29:30.878Z,1656372570.878 [Default:CheckIn](INFO): Running loop #3
2022-06-27T23:29:30.878Z,1656372570.878 [Default:CheckIn] Running Loop=3
2022-06-27T23:29:30.878Z,1656372570.878 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:29:30.878Z,1656372570.878 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:29:32.868Z,1656372572.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232932.00,A,3648.17699,N,12147.27697,W,0.661,16.86,270622,,,A*49
2022-06-27T23:29:32.870Z,1656372572.870 [NAL9602](INFO): GPS fix at 20220627T232932: (36.802950, -121.787949)
2022-06-27T23:29:32.921Z,1656372572.921 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:29:32.921Z,1656372572.921 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:29:40.420Z,1656372580.420 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220627T222746/Courier0016.lzma
2022-06-27T23:29:41.422Z,1656372581.422 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0016.lzma.bak
2022-06-27T23:29:41.423Z,1656372581.423 [DataOverHttps](INFO): SBD MOMSN=16927189
2022-06-27T23:29:51.862Z,1656372591.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=19346, MT Status=2, MTMSN=0
2022-06-27T23:29:51.862Z,1656372591.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-27T23:29:57.932Z,1656372597.932 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220627T222746/Express0017.lzma
2022-06-27T23:29:58.935Z,1656372598.935 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0017.lzma.bak
2022-06-27T23:29:58.935Z,1656372598.935 [DataOverHttps](INFO): SBD MOMSN=16927193
2022-06-27T23:30:00.373Z,1656372600.373 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:30:00.373Z,1656372600.373 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:30:00.373Z,1656372600.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:30:08.829Z,1656372608.829 [NAL9602](INFO): SBD MO Status=2, MOMSN=19346, MT Status=2, MTMSN=0
2022-06-27T23:30:08.830Z,1656372608.830 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-27T23:30:38.724Z,1656372638.724 [NAL9602](INFO): SBD MO Status=2, MOMSN=19346, MT Status=2, MTMSN=0
2022-06-27T23:30:38.724Z,1656372638.724 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-27T23:34:35.487Z,1656372875.487 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-06-27T23:35:00.965Z,1656372900.965 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:35:00.965Z,1656372900.965 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:35:00.965Z,1656372900.965 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:35:00.965Z,1656372900.965 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:35:01.365Z,1656372901.365 [Default:CheckIn:D] Stopped
2022-06-27T23:35:01.365Z,1656372901.365 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.466630 min 
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn:E] Stopped
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn] Stopped
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn](INFO): Running loop #4
2022-06-27T23:35:01.791Z,1656372901.791 [Default:CheckIn] Running Loop=4
2022-06-27T23:35:01.792Z,1656372901.792 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:35:01.792Z,1656372901.792 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:35:03.773Z,1656372903.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233502.00,A,3648.15559,N,12147.28865,W,0.253,16.86,270622,,,A*43
2022-06-27T23:35:03.775Z,1656372903.775 [NAL9602](INFO): GPS fix at 20220627T233502: (36.802593, -121.788144)
2022-06-27T23:35:03.825Z,1656372903.825 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:35:03.825Z,1656372903.825 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:35:11.248Z,1656372911.248 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220627T222746/Courier0019.lzma
2022-06-27T23:35:12.250Z,1656372912.250 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0019.lzma.bak
2022-06-27T23:35:12.251Z,1656372912.251 [DataOverHttps](INFO): SBD MOMSN=16927249
2022-06-27T23:35:28.813Z,1656372928.813 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20220627T222746/Express0020.lzma
2022-06-27T23:35:29.815Z,1656372929.815 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0020.lzma.bak
2022-06-27T23:35:29.815Z,1656372929.815 [DataOverHttps](INFO): SBD MOMSN=16927252
2022-06-27T23:35:31.345Z,1656372931.345 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:35:31.346Z,1656372931.346 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:35:31.346Z,1656372931.346 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:35:36.578Z,1656372936.578 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-27T23:40:31.985Z,1656373231.985 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:40:31.985Z,1656373231.985 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:40:31.985Z,1656373231.985 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:40:31.986Z,1656373231.986 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:40:32.363Z,1656373232.363 [Default:CheckIn:D] Stopped
2022-06-27T23:40:32.363Z,1656373232.363 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.983268 min 
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn:E] Stopped
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn] Stopped
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn](INFO): Running loop #5
2022-06-27T23:40:32.766Z,1656373232.766 [Default:CheckIn] Running Loop=5
2022-06-27T23:40:32.767Z,1656373232.767 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:40:32.767Z,1656373232.767 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:40:34.778Z,1656373234.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234034.00,A,3648.16204,N,12147.28403,W,0.292,16.86,270622,,,A*49
2022-06-27T23:40:34.789Z,1656373234.789 [NAL9602](INFO): GPS fix at 20220627T234034: (36.802701, -121.788067)
2022-06-27T23:40:34.800Z,1656373234.800 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:40:34.800Z,1656373234.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:40:43.008Z,1656373243.008 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220627T222746/Courier0022.lzma
2022-06-27T23:40:44.007Z,1656373244.007 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0022.lzma.bak
2022-06-27T23:40:44.007Z,1656373244.007 [DataOverHttps](INFO): SBD MOMSN=16927256
2022-06-27T23:41:00.742Z,1656373260.742 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220627T222746/Express0023.lzma
2022-06-27T23:41:01.744Z,1656373261.744 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0023.lzma.bak
2022-06-27T23:41:01.744Z,1656373261.744 [DataOverHttps](INFO): SBD MOMSN=16927259
2022-06-27T23:41:03.068Z,1656373263.068 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:41:03.068Z,1656373263.068 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:41:03.068Z,1656373263.068 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:41:05.476Z,1656373265.476 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-06-27T23:41:05.550Z,1656373265.550 [NAL9602](ERROR): received: 
+CSQ:0

OK346, 2, 0, 0, 0

OK
2022-06-27T23:41:13.975Z,1656373273.975 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2022-06-27T23:42:00.886Z,1656373320.886 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2022-06-27T23:42:07.293Z,1656373327.293 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-06-27T23:42:07.295Z,1656373327.295 [BPC1](INFO): Received data from all battery sticks.
2022-06-27T23:43:53.573Z,1656373433.573 [NAL9602](INFO): SBD MO Status=0, MOMSN=19346, MT Status=0, MTMSN=0
2022-06-27T23:43:53.573Z,1656373433.573 [NAL9602](INFO): No messages in MT queue
2022-06-27T23:44:24.284Z,1656373464.284 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-27T23:46:03.682Z,1656373563.682 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:46:03.682Z,1656373563.682 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:46:03.682Z,1656373563.682 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:46:03.682Z,1656373563.682 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:46:04.121Z,1656373564.121 [Default:CheckIn:D] Stopped
2022-06-27T23:46:04.122Z,1656373564.122 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.512569 min 
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn:E] Stopped
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn] Stopped
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:46:04.494Z,1656373564.494 [Default:CheckIn](INFO): Running loop #6
2022-06-27T23:46:04.495Z,1656373564.495 [Default:CheckIn] Running Loop=6
2022-06-27T23:46:04.495Z,1656373564.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:46:04.495Z,1656373564.495 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:46:06.512Z,1656373566.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234605.00,A,3648.16748,N,12147.28001,W,0.097,0.00,270622,,,A*78
2022-06-27T23:46:06.514Z,1656373566.514 [NAL9602](INFO): GPS fix at 20220627T234605: (36.802791, -121.788000)
2022-06-27T23:46:06.525Z,1656373566.525 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:46:06.525Z,1656373566.525 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-27T23:46:14.558Z,1656373574.558 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220627T222746/Courier0025.lzma
2022-06-27T23:46:15.560Z,1656373575.560 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Courier0025.lzma.bak
2022-06-27T23:46:15.560Z,1656373575.560 [DataOverHttps](INFO): SBD MOMSN=16927318
2022-06-27T23:46:29.197Z,1656373589.197 [NAL9602](INFO): SBD MO Status=0, MOMSN=19347, MT Status=0, MTMSN=0
2022-06-27T23:46:29.197Z,1656373589.197 [NAL9602](INFO): No messages in MT queue
2022-06-27T23:46:35.242Z,1656373595.242 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220627T222746/Express0026.lzma
2022-06-27T23:46:36.244Z,1656373596.244 [DataOverHttps](INFO): Moved sent file to Logs/20220627T222746/Express0026.lzma.bak
2022-06-27T23:46:36.245Z,1656373596.245 [DataOverHttps](INFO): SBD MOMSN=16927322
2022-06-27T23:46:37.708Z,1656373597.708 [Default:CheckIn:Read_Iridium] Stopped
2022-06-27T23:46:37.708Z,1656373597.708 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-27T23:46:37.708Z,1656373597.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-27T23:46:59.900Z,1656373619.900 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-27T23:47:08.399Z,1656373628.399 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-06-27T23:49:33.215Z,1656373773.215 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.799103
2022-06-27T23:49:44.012Z,1656373784.012 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.008889
2022-06-27T23:51:38.384Z,1656373898.384 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-27T23:51:38.384Z,1656373898.384 [Default:CheckIn:C.Wait] Stopped
2022-06-27T23:51:38.385Z,1656373898.385 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-27T23:51:38.385Z,1656373898.385 [Default:CheckIn:D] Running Loop=1
2022-06-27T23:51:38.708Z,1656373898.708 [Default:CheckIn:D] Stopped
2022-06-27T23:51:38.708Z,1656373898.708 [Default:CheckIn:E] Running Loop=1
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.089010 min 
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn:E] Stopped
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn] Stopped
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn](INFO): Running loop #7
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn] Running Loop=7
2022-06-27T23:51:39.111Z,1656373899.111 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-27T23:51:39.112Z,1656373899.112 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-27T23:56:19.516Z,1656374179.516 [CommandExec](IMPORTANT): got command quit
2022-06-27T23:56:20.518Z,1656374180.518 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-06-27T23:56:20.519Z,1656374180.519 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:20.519Z,1656374180.519 [CommandExec](INFO): Uninitializing the command executive.
2022-06-27T23:56:20.519Z,1656374180.519 [CommandExec](INFO): Uninitializing the command scheduler.
2022-06-27T23:56:20.519Z,1656374180.519 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:20.654Z,1656374180.654 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-06-27T23:56:20.655Z,1656374180.655 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-06-27T23:56:20.655Z,1656374180.655 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:20.655Z,1656374180.655 [NavChartDb](INFO): Join timeout helper Thread ID is 1393
2022-06-27T23:56:20.807Z,1656374180.807 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:20.807Z,1656374180.807 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:20.823Z,1656374180.823 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2022-06-27T23:56:20.823Z,1656374180.823 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:20.823Z,1656374180.823 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 1394
2022-06-27T23:56:21.175Z,1656374181.175 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:21.175Z,1656374181.175 [WetLabsUBAT](INFO): Powering down
2022-06-27T23:56:21.176Z,1656374181.176 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:21.199Z,1656374181.199 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-06-27T23:56:21.199Z,1656374181.199 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:21.199Z,1656374181.199 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1395
2022-06-27T23:56:21.575Z,1656374181.575 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:21.575Z,1656374181.575 [WetLabsBB2FL](INFO): Powering down
2022-06-27T23:56:21.576Z,1656374181.576 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:21.579Z,1656374181.579 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-06-27T23:56:21.579Z,1656374181.579 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:21.579Z,1656374181.579 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1396
2022-06-27T23:56:22.251Z,1656374182.251 [CTD_Seabird](INFO): Powering down
2022-06-27T23:56:22.262Z,1656374182.262 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:22.263Z,1656374182.263 [CTD_Seabird](INFO): Powering down
2022-06-27T23:56:22.274Z,1656374182.274 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.283Z,1656374182.283 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-06-27T23:56:22.284Z,1656374182.284 [DAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.284Z,1656374182.284 [DAT](INFO): Join timeout helper Thread ID is 1397
2022-06-27T23:56:22.287Z,1656374182.287 [DAT](INFO): Powering down
2022-06-27T23:56:22.359Z,1656374182.359 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:22.359Z,1656374182.359 [DAT](INFO): Powering down
2022-06-27T23:56:22.360Z,1656374182.360 [DAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.363Z,1656374182.363 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-06-27T23:56:22.364Z,1656374182.364 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.364Z,1656374182.364 [Radio_Surface](INFO): Join timeout helper Thread ID is 1398
2022-06-27T23:56:22.459Z,1656374182.459 [Radio_Surface](INFO): Powering down
2022-06-27T23:56:22.460Z,1656374182.460 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:22.460Z,1656374182.460 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.463Z,1656374182.463 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-06-27T23:56:22.463Z,1656374182.463 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:22.464Z,1656374182.464 [Onboard](INFO): Join timeout helper Thread ID is 1399
2022-06-27T23:56:23.283Z,1656374183.283 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-06-27T23:56:23.431Z,1656374183.431 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:23.431Z,1656374183.431 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:23.439Z,1656374183.439 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-06-27T23:56:23.439Z,1656374183.439 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:23.440Z,1656374183.440 [DataOverHttps](INFO): Join timeout helper Thread ID is 1400
2022-06-27T23:56:24.287Z,1656374184.287 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:24.287Z,1656374184.287 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.299Z,1656374184.299 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-06-27T23:56:24.299Z,1656374184.299 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.300Z,1656374184.300 [BackseatComponent](INFO): Join timeout helper Thread ID is 1401
2022-06-27T23:56:24.355Z,1656374184.355 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:24.355Z,1656374184.355 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.371Z,1656374184.371 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-06-27T23:56:24.371Z,1656374184.371 [logger ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.372Z,1656374184.372 [logger](INFO): Join timeout helper Thread ID is 1402
2022-06-27T23:56:24.410Z,1656374184.410 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:24.410Z,1656374184.410 [logger ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.419Z,1656374184.419 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-06-27T23:56:24.419Z,1656374184.419 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.420Z,1656374184.420 [CommandLine](INFO): Join timeout helper Thread ID is 1403
2022-06-27T23:56:24.483Z,1656374184.483 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:24.483Z,1656374184.483 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.499Z,1656374184.499 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-06-27T23:56:24.499Z,1656374184.499 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.500Z,1656374184.500 [CommandExec](INFO): Join timeout helper Thread ID is 1404
2022-06-27T23:56:24.501Z,1656374184.501 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-06-27T23:56:24.501Z,1656374184.501 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.501Z,1656374184.501 [controlThread](INFO): Join timeout helper Thread ID is 1405
2022-06-27T23:56:24.671Z,1656374184.671 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-06-27T23:56:24.671Z,1656374184.671 [controlThread](DEBUG): Uninitializing ControlThread
2022-06-27T23:56:24.671Z,1656374184.671 [AHRS_M2](INFO): Powering down
2022-06-27T23:56:24.743Z,1656374184.743 [NAL9602](INFO): Powering down
2022-06-27T23:56:24.815Z,1656374184.815 [RDI_Pathfinder](INFO): Powering down
2022-06-27T23:56:24.816Z,1656374184.816 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-06-27T23:56:24.817Z,1656374184.817 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-06-27T23:56:24.817Z,1656374184.817 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-06-27T23:56:24.818Z,1656374184.818 [MissionManager](INFO): Uninitializing Mission Default
2022-06-27T23:56:24.818Z,1656374184.818 [Default] Stopped
2022-06-27T23:56:24.818Z,1656374184.818 [Default](DEBUG): Aggregate::uninitialize Default
2022-06-27T23:56:24.818Z,1656374184.818 [Default:B.GoToSurface] Stopped
2022-06-27T23:56:24.818Z,1656374184.818 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-06-27T23:56:24.818Z,1656374184.818 [Default:CheckIn] Stopped
2022-06-27T23:56:24.818Z,1656374184.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-27T23:56:24.818Z,1656374184.818 [Default:CheckIn:Read_GPS] Stopped
2022-06-27T23:56:24.821Z,1656374184.821 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-06-27T23:56:24.821Z,1656374184.821 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-06-27T23:56:24.822Z,1656374184.822 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-06-27T23:56:24.822Z,1656374184.822 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-06-27T23:56:24.822Z,1656374184.822 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-06-27T23:56:24.823Z,1656374184.823 [BuoyancyServo](INFO): Powering down
2022-06-27T23:56:24.835Z,1656374184.835 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-06-27T23:56:24.835Z,1656374184.835 [ElevatorServo](INFO): Powering down
2022-06-27T23:56:24.835Z,1656374184.835 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-06-27T23:56:24.836Z,1656374184.836 [MassServo](INFO): Powering down
2022-06-27T23:56:24.836Z,1656374184.836 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-06-27T23:56:24.837Z,1656374184.837 [RudderServo](INFO): Powering down
2022-06-27T23:56:24.837Z,1656374184.837 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2022-06-27T23:56:24.837Z,1656374184.837 [ThrusterServo](INFO): Powering down
2022-06-27T23:56:24.838Z,1656374184.838 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-06-27T23:56:24.839Z,1656374184.839 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-06-27T23:56:24.839Z,1656374184.839 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-06-27T23:56:24.839Z,1656374184.839 [CBIT](DEBUG): Powering off loads.
2022-06-27T23:56:24.850Z,1656374184.850 [CBIT](DEBUG): Disabling WDT.
2022-06-27T23:56:24.862Z,1656374184.862 [CBIT](DEBUG): Opening all GF detection circuits.
2022-06-27T23:56:24.863Z,1656374184.863 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.919Z,1656374184.919 [DAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.927Z,1656374184.927 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.928Z,1656374184.928 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.934Z,1656374184.934 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:24.977Z,1656374184.977 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:25.034Z,1656374185.034 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:25.036Z,1656374185.036 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:25.039Z,1656374185.039 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:25.047Z,1656374185.047 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-06-27T23:56:25.126Z,1656374185.126 [logger ThreadHandler](INFO): Thread cancelled.