2022-10-17T17:49:41.152Z,1666028981.152 [Supervisor](DEBUG): Initializing supervisor.
2022-10-17T17:49:41.156Z,1666028981.156 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-10-17T17:49:41.157Z,1666028981.157 [SyncHandler](INFO): Protected caller Thread ID is 5132
2022-10-17T17:49:41.157Z,1666028981.157 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-10-17T17:49:41.158Z,1666028981.158 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-10-17T17:49:41.159Z,1666028981.159 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5133
2022-10-17T17:49:41.163Z,1666028981.163 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-10-17T17:49:41.180Z,1666028981.180 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-10-17T17:49:41.181Z,1666028981.181 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-10-17T17:49:41.181Z,1666028981.181 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5134
2022-10-17T17:49:41.185Z,1666028981.185 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-10-17T17:49:41.186Z,1666028981.186 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-10-17T17:49:41.187Z,1666028981.187 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5135
2022-10-17T17:49:41.189Z,1666028981.189 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-10-17T17:49:41.190Z,1666028981.190 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-10-17T17:49:41.190Z,1666028981.190 [logger ThreadHandler](INFO): Protected caller Thread ID is 5136
2022-10-17T17:49:41.194Z,1666028981.194 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-10-17T17:49:41.194Z,1666028981.194 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-10-17T17:49:41.196Z,1666028981.196 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-10-17T17:49:41.309Z,1666028981.309 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-10-17T17:49:41.310Z,1666028981.310 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-10-17T17:49:41.921Z,1666028981.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-10-17T17:49:41.922Z,1666028981.922 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-10-17T17:49:42.131Z,1666028982.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-10-17T17:49:42.132Z,1666028982.132 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-10-17T17:49:42.208Z,1666028982.208 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-10-17T17:49:42.334Z,1666028982.334 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-10-17T17:49:42.335Z,1666028982.335 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-10-17T17:49:42.414Z,1666028982.414 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-10-17T17:49:42.518Z,1666028982.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-10-17T17:49:42.519Z,1666028982.519 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-10-17T17:49:42.870Z,1666028982.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-10-17T17:49:42.871Z,1666028982.871 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-10-17T17:49:43.337Z,1666028983.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-10-17T17:49:43.338Z,1666028983.338 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-10-17T17:49:43.544Z,1666028983.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-10-17T17:49:43.545Z,1666028983.545 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-10-17T17:49:43.719Z,1666028983.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-10-17T17:49:43.720Z,1666028983.720 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-10-17T17:49:44.171Z,1666028984.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-10-17T17:49:44.172Z,1666028984.172 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-10-17T17:49:44.443Z,1666028984.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-10-17T17:49:44.444Z,1666028984.444 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-10-17T17:49:44.648Z,1666028984.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-10-17T17:49:44.649Z,1666028984.649 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-10-17T17:49:45.000Z,1666028985.000 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-10-17T17:49:45.002Z,1666028985.002 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-10-17T17:49:45.320Z,1666028985.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-10-17T17:49:45.322Z,1666028985.322 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2022-10-17T17:49:45.323Z,1666028985.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2022-10-17T17:49:45.406Z,1666028985.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2022-10-17T17:49:45.561Z,1666028985.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2022-10-17T17:49:45.670Z,1666028985.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2022-10-17T17:49:45.756Z,1666028985.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2022-10-17T17:49:45.875Z,1666028985.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2022-10-17T17:49:46.930Z,1666028986.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2022-10-17T17:49:47.192Z,1666028987.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-10-17T17:49:47.193Z,1666028987.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2022-10-17T17:49:47.285Z,1666028987.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2022-10-17T17:49:47.381Z,1666028987.381 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2022-10-17T17:49:47.516Z,1666028987.516 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2022-10-17T17:49:47.612Z,1666028987.612 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-10-17T17:49:47.628Z,1666028987.628 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-10-17T17:49:47.727Z,1666028987.727 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-10-17T17:49:47.728Z,1666028987.728 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-10-17T17:49:47.777Z,1666028987.777 [VerticalControl](DEBUG): Construct VerticalControl.
2022-10-17T17:49:47.834Z,1666028987.834 [VerticalControl] Loaded
2022-10-17T17:49:47.834Z,1666028987.834 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-10-17T17:49:47.837Z,1666028987.837 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-10-17T17:49:47.878Z,1666028987.878 [HorizontalControl] Loaded
2022-10-17T17:49:47.878Z,1666028987.878 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-10-17T17:49:47.880Z,1666028987.880 [SpeedControl](DEBUG): Construct SpeedControl.
2022-10-17T17:49:47.883Z,1666028987.883 [SpeedControl] Loaded
2022-10-17T17:49:47.884Z,1666028987.884 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-10-17T17:49:47.886Z,1666028987.886 [LoopControl](DEBUG): Construct LoopControl.
2022-10-17T17:49:47.887Z,1666028987.887 [LoopControl] Loaded
2022-10-17T17:49:47.887Z,1666028987.887 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-10-17T17:49:47.887Z,1666028987.887 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-10-17T17:49:47.888Z,1666028987.888 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-10-17T17:49:47.938Z,1666028987.938 [DepthRateCalculator] Loaded
2022-10-17T17:49:47.938Z,1666028987.938 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-10-17T17:49:47.943Z,1666028987.943 [PitchRateCalculator] Loaded
2022-10-17T17:49:47.943Z,1666028987.943 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-10-17T17:49:47.953Z,1666028987.953 [SpeedCalculator] Loaded
2022-10-17T17:49:47.953Z,1666028987.953 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-10-17T17:49:47.957Z,1666028987.957 [YawRateCalculator] Loaded
2022-10-17T17:49:47.957Z,1666028987.957 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-10-17T17:49:47.975Z,1666028987.975 [ElevatorOffsetCalculator] Loaded
2022-10-17T17:49:47.975Z,1666028987.975 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-10-17T17:49:47.976Z,1666028987.976 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-10-17T17:49:47.976Z,1666028987.976 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-10-17T17:49:48.007Z,1666028988.007 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-10-17T17:49:48.007Z,1666028988.007 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-10-17T17:49:48.067Z,1666028988.067 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-10-17T17:49:48.068Z,1666028988.068 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-10-17T17:49:48.384Z,1666028988.384 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-10-17T17:49:48.384Z,1666028988.384 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-10-17T17:49:48.536Z,1666028988.536 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-10-17T17:49:48.536Z,1666028988.536 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-10-17T17:49:48.963Z,1666028988.963 [AHRS_M2] Loaded
2022-10-17T17:49:48.963Z,1666028988.963 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-10-17T17:49:49.046Z,1666028989.046 [BackseatComponent] Loaded
2022-10-17T17:49:49.047Z,1666028989.047 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-10-17T17:49:49.050Z,1666028989.050 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409644E0
2022-10-17T17:49:49.050Z,1666028989.050 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5219
2022-10-17T17:49:49.053Z,1666028989.053 [LcmUniversalReporter] Loaded
2022-10-17T17:49:49.053Z,1666028989.053 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-10-17T17:49:49.839Z,1666028989.839 [BPC1] Loaded
2022-10-17T17:49:49.839Z,1666028989.839 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-10-17T17:49:49.919Z,1666028989.919 [DataOverHttps] Loaded
2022-10-17T17:49:49.919Z,1666028989.919 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-10-17T17:49:49.920Z,1666028989.920 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409944E0
2022-10-17T17:49:49.920Z,1666028989.920 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5220
2022-10-17T17:49:49.941Z,1666028989.941 [Depth_Keller] Loaded
2022-10-17T17:49:49.941Z,1666028989.941 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-10-17T17:49:49.946Z,1666028989.946 [DropWeight] Loaded
2022-10-17T17:49:49.946Z,1666028989.946 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-10-17T17:49:50.007Z,1666028990.007 [NAL9602] Loaded
2022-10-17T17:49:50.007Z,1666028990.007 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-10-17T17:49:50.036Z,1666028990.036 [Onboard] Loaded
2022-10-17T17:49:50.037Z,1666028990.037 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-10-17T17:49:50.038Z,1666028990.038 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409C44E0
2022-10-17T17:49:50.038Z,1666028990.038 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5221
2022-10-17T17:49:50.050Z,1666028990.050 [Power24vConverter] Loaded
2022-10-17T17:49:50.050Z,1666028990.050 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-10-17T17:49:50.063Z,1666028990.063 [Radio_Surface] Loaded
2022-10-17T17:49:50.063Z,1666028990.063 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-10-17T17:49:50.064Z,1666028990.064 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409F44E0
2022-10-17T17:49:50.065Z,1666028990.065 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5222
2022-10-17T17:49:50.109Z,1666028990.109 [RDI_Pathfinder] Loaded
2022-10-17T17:49:50.109Z,1666028990.109 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-10-17T17:49:50.198Z,1666028990.198 [DAT] Loaded
2022-10-17T17:49:50.199Z,1666028990.199 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-10-17T17:49:50.200Z,1666028990.200 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0
2022-10-17T17:49:50.200Z,1666028990.200 [DAT ThreadHandler](INFO): Protected caller Thread ID is 5223
2022-10-17T17:49:50.200Z,1666028990.200 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-10-17T17:49:50.201Z,1666028990.201 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-10-17T17:49:50.317Z,1666028990.317 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-10-17T17:49:50.317Z,1666028990.317 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-10-17T17:49:50.331Z,1666028990.331 [NavChart] Loaded
2022-10-17T17:49:50.331Z,1666028990.331 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-10-17T17:49:50.337Z,1666028990.337 [UniversalFixResidualReporter] Loaded
2022-10-17T17:49:50.337Z,1666028990.337 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-10-17T17:49:50.337Z,1666028990.337 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-10-17T17:49:50.338Z,1666028990.338 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-10-17T17:49:50.478Z,1666028990.478 [SBIT](DEBUG): Construct Startup Built In Test.
2022-10-17T17:49:50.487Z,1666028990.487 [SBIT] Loaded
2022-10-17T17:49:50.487Z,1666028990.487 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-10-17T17:49:50.490Z,1666028990.490 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-10-17T17:49:50.502Z,1666028990.502 [IBIT] Loaded
2022-10-17T17:49:50.503Z,1666028990.503 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-10-17T17:49:50.508Z,1666028990.508 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-10-17T17:49:50.610Z,1666028990.610 [CBIT] Loaded
2022-10-17T17:49:50.610Z,1666028990.610 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-10-17T17:49:50.610Z,1666028990.610 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-10-17T17:49:50.611Z,1666028990.611 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-10-17T17:49:50.741Z,1666028990.741 [BuoyancyServo] Loaded
2022-10-17T17:49:50.742Z,1666028990.742 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-10-17T17:49:50.763Z,1666028990.763 [ElevatorServo] Loaded
2022-10-17T17:49:50.763Z,1666028990.763 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-10-17T17:49:50.782Z,1666028990.782 [MassServo] Loaded
2022-10-17T17:49:50.783Z,1666028990.783 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-10-17T17:49:50.801Z,1666028990.801 [RudderServo] Loaded
2022-10-17T17:49:50.801Z,1666028990.801 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-10-17T17:49:50.818Z,1666028990.818 [ThrusterServo] Loaded
2022-10-17T17:49:50.819Z,1666028990.819 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-10-17T17:49:50.819Z,1666028990.819 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-10-17T17:49:50.820Z,1666028990.820 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-10-17T17:49:50.833Z,1666028990.833 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-10-17T17:49:50.833Z,1666028990.833 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-10-17T17:49:51.017Z,1666028991.017 [CTD_Seabird] Loaded
2022-10-17T17:49:51.018Z,1666028991.018 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-10-17T17:49:51.020Z,1666028991.020 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-10-17T17:49:51.020Z,1666028991.020 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5224
2022-10-17T17:49:51.041Z,1666028991.041 [PAR_Licor] Loaded
2022-10-17T17:49:51.041Z,1666028991.041 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-10-17T17:49:51.072Z,1666028991.072 [WetLabsBB2FL] Loaded
2022-10-17T17:49:51.072Z,1666028991.072 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-10-17T17:49:51.073Z,1666028991.073 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B9E4E0
2022-10-17T17:49:51.073Z,1666028991.073 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5225
2022-10-17T17:49:51.093Z,1666028991.093 [WetLabsUBAT] Loaded
2022-10-17T17:49:51.093Z,1666028991.093 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2022-10-17T17:49:51.094Z,1666028991.094 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BCE4E0
2022-10-17T17:49:51.094Z,1666028991.094 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 5226
2022-10-17T17:49:51.095Z,1666028991.095 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-10-17T17:49:51.129Z,1666028991.129 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-10-17T17:49:51.132Z,1666028991.132 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-10-17T17:49:51.231Z,1666028991.231 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-10-17T17:49:51.238Z,1666028991.238 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BFE4E0
2022-10-17T17:49:51.238Z,1666028991.238 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5227
2022-10-17T17:49:51.360Z,1666028991.360 [Supervisor](INFO): Main Thread ID is 5131
2022-10-17T17:49:51.360Z,1666028991.360 [Supervisor](DEBUG): Running supervisor.
2022-10-17T17:49:51.360Z,1666028991.360 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5228
2022-10-17T17:49:51.361Z,1666028991.361 [CommandExec](INFO): Initializing the command executive.
2022-10-17T17:49:51.363Z,1666028991.363 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5229
2022-10-17T17:49:51.365Z,1666028991.365 [controlThread ThreadHandler](INFO): Handler Thread ID is 5230
2022-10-17T17:49:51.366Z,1666028991.366 [controlThread](DEBUG): Initializing ControlThread
2022-10-17T17:49:51.367Z,1666028991.367 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-10-17T17:49:51.368Z,1666028991.368 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-10-17T17:49:51.369Z,1666028991.369 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-10-17T17:49:51.369Z,1666028991.369 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-10-17T17:49:51.370Z,1666028991.370 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-10-17T17:49:51.370Z,1666028991.370 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-10-17T17:49:51.371Z,1666028991.371 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-10-17T17:49:51.371Z,1666028991.371 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-10-17T17:49:51.371Z,1666028991.371 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-10-17T17:49:51.376Z,1666028991.376 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-10-17T17:49:51.377Z,1666028991.377 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-10-17T17:49:51.377Z,1666028991.377 [SBIT](INFO): Initialize SBIT Component.
2022-10-17T17:49:51.378Z,1666028991.378 [SBIT](IMPORTANT): git: 2022-09-08
2022-10-17T17:49:51.378Z,1666028991.378 [SBIT](INFO): git hash: 1923f3a7c5c14ef35d1c7a327e27a495a1a7ac01
2022-10-17T17:49:51.378Z,1666028991.378 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-10-17T17:49:51.379Z,1666028991.379 [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-10-17T17:49:51.380Z,1666028991.380 [SBIT](INFO): Beginning SBIT in 40.000000 seconds.
2022-10-17T17:49:51.381Z,1666028991.381 [IBIT](INFO): Initialize IBIT Component.
2022-10-17T17:49:51.382Z,1666028991.382 [CBIT](DEBUG): Initialize CBIT Component.
2022-10-17T17:49:51.383Z,1666028991.383 [logger ThreadHandler](INFO): Handler Thread ID is 5231
2022-10-17T17:49:51.394Z,1666028991.394 [CBIT](DEBUG): Initialized mux pins.
2022-10-17T17:49:51.394Z,1666028991.394 [CBIT](DEBUG): Initializing the watchdog timer.
2022-10-17T17:49:51.403Z,1666028991.403 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5232
2022-10-17T17:49:51.414Z,1666028991.414 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5233
2022-10-17T17:49:51.415Z,1666028991.415 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-10-17T17:49:51.418Z,1666028991.418 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-10-17T17:49:51.419Z,1666028991.419 [CBIT](DEBUG): Initializing heartbeat.
2022-10-17T17:49:51.427Z,1666028991.427 [Onboard ThreadHandler](INFO): Handler Thread ID is 5234
2022-10-17T17:49:51.448Z,1666028991.448 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5235
2022-10-17T17:49:51.467Z,1666028991.467 [DAT ThreadHandler](INFO): Handler Thread ID is 5236
2022-10-17T17:49:51.467Z,1666028991.467 [DAT](INFO): Powering up
2022-10-17T17:49:51.468Z,1666028991.468 [DAT](DEBUG): Initializing DAT.
2022-10-17T17:49:51.471Z,1666028991.471 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5238
2022-10-17T17:49:51.472Z,1666028991.472 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-10-17T17:49:51.475Z,1666028991.475 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5240
2022-10-17T17:49:51.478Z,1666028991.478 [WetLabsBB2FL](INFO): Powering up
2022-10-17T17:49:51.480Z,1666028991.480 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 5242
2022-10-17T17:49:51.483Z,1666028991.483 [WetLabsUBAT](INFO): Powering up
2022-10-17T17:49:51.485Z,1666028991.485 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5244
2022-10-17T17:49:51.490Z,1666028991.490 [CBIT](DEBUG): Deactivating GF circuits.
2022-10-17T17:49:51.490Z,1666028991.490 [CBIT](DEBUG): Deactivating emergency mode.
2022-10-17T17:49:51.491Z,1666028991.491 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-10-17T17:49:51.492Z,1666028991.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-10-17T17:49:51.493Z,1666028991.493 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-10-17T17:49:51.528Z,1666028991.528 [CBIT](DEBUG): Backplane powered.
2022-10-17T17:49:51.544Z,1666028991.544 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-10-17T17:49:51.583Z,1666028991.583 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-17T17:49:51.618Z,1666028991.618 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2022-10-17T17:49:51.619Z,1666028991.619 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-10-17T17:49:51.708Z,1666028991.708 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-10-17T17:49:51.709Z,1666028991.709 [Default:A.Wait](DEBUG): Construct Wait.
2022-10-17T17:49:51.731Z,1666028991.731 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-17T17:49:51.758Z,1666028991.758 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-10-17T17:49:51.761Z,1666028991.761 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-10-17T17:49:51.787Z,1666028991.787 [Default:E.Execute](DEBUG): Construct Execute.
2022-10-17T17:49:51.806Z,1666028991.806 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-10-17T17:49:51.811Z,1666028991.811 [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-10-17T17:49:51.822Z,1666028991.822 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-10-17T17:49:51.854Z,1666028991.854 [Radio_Surface](INFO): Powering up
2022-10-17T17:49:51.929Z,1666028991.929 [Power24vConverter](INFO): Powering up.
2022-10-17T17:49:51.930Z,1666028991.930 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-10-17T17:49:51.988Z,1666028991.988 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:51.994Z,1666028991.994 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-10-17T17:49:51.995Z,1666028991.995 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:52.002Z,1666028992.002 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-10-17T17:49:52.003Z,1666028992.003 [MassServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:52.010Z,1666028992.010 [MassServo](DEBUG): Initializing MassServo.
2022-10-17T17:49:52.011Z,1666028992.011 [RudderServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:52.018Z,1666028992.018 [RudderServo](DEBUG): Initializing RudderServo.
2022-10-17T17:49:52.019Z,1666028992.019 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:52.026Z,1666028992.026 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-10-17T17:49:52.950Z,1666028992.950 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-10-17T17:49:52.950Z,1666028992.950 [RudderServo](FAULT): Rudder failed to initialize
2022-10-17T17:49:52.950Z,1666028992.950 [RudderServo] Communications Fault, FailCount= 1
2022-10-17T17:49:52.950Z,1666028992.950 [RudderServo](ERROR): Communications Fault
2022-10-17T17:49:53.051Z,1666028993.051 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-10-17T17:49:53.259Z,1666028993.259 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-10-17T17:49:53.259Z,1666028993.259 [RudderServo](INFO): Powering down
2022-10-17T17:49:53.951Z,1666028993.951 [RudderServo](DEBUG): Initializing EZServoServo.
2022-10-17T17:49:54.071Z,1666028994.071 [RudderServo](DEBUG): Initializing RudderServo.
2022-10-17T17:49:54.075Z,1666028994.075 [CBIT](INFO): Clearing failed state for component RudderServo
2022-10-17T17:49:54.075Z,1666028994.075 [RudderServo] No Fault, FailCount= 1
2022-10-17T17:49:54.090Z,1666028994.090 [WetLabsBB2FL](INFO): Powering down
2022-10-17T17:49:58.506Z,1666028998.506 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-10-17T17:50:00.762Z,1666029000.762 [WetLabsUBAT](INFO): Powering down
2022-10-17T17:50:03.315Z,1666029003.315 [DAT](INFO): DAT read: 

2022-10-17T17:50:03.316Z,1666029003.316 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-10-17T17:50:05.084Z,1666029005.084 [DAT](INFO): DAT read: MF Frequency Band

2022-10-17T17:50:05.085Z,1666029005.085 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-10-17T17:50:05.086Z,1666029005.086 [DAT](INFO): DAT read: Oct 17 2022 17:49:59 

2022-10-17T17:50:05.682Z,1666029005.682 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005930
2022-10-17T17:50:06.087Z,1666029006.087 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-10-17T17:50:06.088Z,1666029006.088 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-10-17T17:50:06.089Z,1666029006.089 [DAT](INFO): commRate: 800
2022-10-17T17:50:08.154Z,1666029008.154 [DAT](INFO): entering command mode
2022-10-17T17:50:08.355Z,1666029008.355 [DAT](INFO): DAT read: 

2022-10-17T17:50:08.355Z,1666029008.355 [DAT](INFO): DAT read: user:1>

2022-10-17T17:50:08.356Z,1666029008.356 [DAT](INFO): setting verbose to 3
2022-10-17T17:50:08.607Z,1666029008.607 [DAT](INFO): DAT read: user:1>

2022-10-17T17:50:08.608Z,1666029008.608 [DAT](INFO): DAT read: Verbose         | 3           

2022-10-17T17:50:08.608Z,1666029008.608 [DAT](INFO): set verbose to 3
2022-10-17T17:50:08.608Z,1666029008.608 [DAT](INFO): setting DatVerbose to 27440
2022-10-17T17:50:08.859Z,1666029008.859 [DAT](INFO): DAT read: user:2>

2022-10-17T17:50:08.860Z,1666029008.860 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-10-17T17:50:08.860Z,1666029008.860 [DAT](INFO): set DatVerbose to 27440
2022-10-17T17:50:08.860Z,1666029008.860 [DAT](INFO): setting transmit power to 8
2022-10-17T17:50:09.111Z,1666029009.111 [DAT](INFO): DAT read: user:3>

2022-10-17T17:50:09.112Z,1666029009.112 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-10-17T17:50:09.112Z,1666029009.112 [DAT](INFO): set transmit power to 8
2022-10-17T17:50:09.112Z,1666029009.112 [DAT](INFO): setting local address to 9
2022-10-17T17:50:09.363Z,1666029009.363 [DAT](INFO): DAT read: user:4>

2022-10-17T17:50:09.364Z,1666029009.364 [DAT](INFO): DAT read: LocalAddr       | 9           

2022-10-17T17:50:09.364Z,1666029009.364 [DAT](INFO): set local address to 9
2022-10-17T17:50:09.365Z,1666029009.365 [DAT](INFO): Setting time to: 17:50:9 And date to:10/17/2022
2022-10-17T17:50:09.615Z,1666029009.615 [DAT](INFO): DAT read: user:5>

2022-10-17T17:50:09.616Z,1666029009.616 [DAT](INFO): DAT read: Mon Oct 17, 2022  17:50:09  

2022-10-17T17:50:09.616Z,1666029009.616 [DAT](INFO): Local DAT time set to Mon Oct 17, 2022  17:50:09  

2022-10-17T17:50:20.132Z,1666029020.132 [NAL9602](INFO): Powering up NAL9602
2022-10-17T17:50:31.052Z,1666029031.052 [NAL9602](INFO): NAL9602 initialized
2022-10-17T17:50:31.867Z,1666029031.867 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-10-17T17:50:31.913Z,1666029031.913 [SBIT](IMPORTANT): Beginning Startup BIT
2022-10-17T17:50:31.958Z,1666029031.958 [CBIT](IMPORTANT): Beginning ground fault scan
2022-10-17T17:50:42.831Z,1666029042.831 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008158
CHAN A1 (24V): 0.001358
CHAN A2 (12V): -0.007538
CHAN A3 (5V): -0.002009
CHAN B0 (3.3V): 0.000343
CHAN B1 (3.15aV): -0.000049
CHAN B2 (3.15bV): -0.000069
CHAN B3 (GND): 0.001957
OPEN: 0.005076
Full Scale: +/- 1 mA
2022-10-17T17:51:25.735Z,1666029085.735 [SBIT](IMPORTANT): SBIT PASSED
2022-10-17T17:51:25.735Z,1666029085.735 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-10-17T17:51:25.736Z,1666029085.736 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-10-17T17:51:25.736Z,1666029085.736 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-10-17T17:51:25.736Z,1666029085.736 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): DAT.verbosity=2 count;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): Express none _.adinos;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): Express none _.aother;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-10-17T17:51:25.737Z,1666029085.737 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-10-17T17:51:25.738Z,1666029085.738 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-10-17T17:51:25.738Z,1666029085.738 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-10-17T17:51:25.738Z,1666029085.738 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-10-17T17:51:25.738Z,1666029085.738 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=317.863121 cubic_centimeter;

2022-10-17T17:51:25.738Z,1666029085.738 [SBIT](IMPORTANT): VerticalControl.massDefault=5.207977 millimeter;

2022-10-17T17:51:26.145Z,1666029086.145 [MissionManager](IMPORTANT): Started mission Startup
2022-10-17T17:51:26.145Z,1666029086.145 [Startup] Running Loop=1
2022-10-17T17:51:26.146Z,1666029086.146 [Startup](DEBUG): Aggregate::initialize Startup
2022-10-17T17:51:26.146Z,1666029086.146 [Startup:A.GoToSurface] Running Loop=1
2022-10-17T17:51:26.146Z,1666029086.146 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-17T17:51:26.147Z,1666029086.147 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-17T17:51:26.147Z,1666029086.147 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-17T17:51:26.147Z,1666029086.147 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-17T17:51:26.148Z,1666029086.148 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-17T17:51:26.148Z,1666029086.148 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-17T17:51:26.149Z,1666029086.149 [Startup:StartupSatComms] Running Loop=1
2022-10-17T17:51:26.150Z,1666029086.150 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-10-17T17:51:26.150Z,1666029086.150 [Startup:StartupSatComms:A] Running Loop=1
2022-10-17T17:51:26.460Z,1666029086.460 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-10-17T17:52:26.197Z,1666029146.197 [Startup:StartupSatComms:A](INFO): Timed out from 2022-10-17T17:51:26.1Z
2022-10-17T17:52:26.197Z,1666029146.197 [Startup:StartupSatComms:A] Stopped
2022-10-17T17:52:26.197Z,1666029146.197 [Startup:StartupSatComms:B] Running Loop=1
2022-10-17T17:52:26.611Z,1666029146.611 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-17T17:52:33.598Z,1666029153.598 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221014T223605/Courier0010.lzma
2022-10-17T17:52:34.600Z,1666029154.600 [DataOverHttps](INFO): Moved sent file to Logs/20221014T223605/Courier0010.lzma.bak
2022-10-17T17:52:34.600Z,1666029154.600 [DataOverHttps](INFO): SBD MOMSN=17246591
2022-10-17T17:52:50.918Z,1666029170.918 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221017T174941/Courier0000.lzma
2022-10-17T17:52:51.675Z,1666029171.675 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-10-17T17:52:51.675Z,1666029171.675 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T17:52:51.738Z,1666029171.738 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T17:52:51.920Z,1666029171.920 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0000.lzma.bak
2022-10-17T17:52:51.920Z,1666029171.920 [DataOverHttps](INFO): SBD MOMSN=17246593
2022-10-17T17:52:52.130Z,1666029172.130 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T17:52:52.130Z,1666029172.130 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-10-17T17:53:08.617Z,1666029188.617 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221014T223605/Express0011.lzma
2022-10-17T17:53:09.620Z,1666029189.620 [DataOverHttps](INFO): Moved sent file to Logs/20221014T223605/Express0011.lzma.bak
2022-10-17T17:53:09.620Z,1666029189.620 [DataOverHttps](INFO): SBD MOMSN=17246597
2022-10-17T17:53:26.147Z,1666029206.147 [DataOverHttps](INFO): Sending 1038 bytes from file Logs/20221017T174941/Express0001.lzma
2022-10-17T17:53:26.433Z,1666029206.433 [Startup:StartupSatComms:B](INFO): Timed out from 2022-10-17T17:52:26.2Z
2022-10-17T17:53:26.433Z,1666029206.433 [Startup:StartupSatComms:B] Stopped
2022-10-17T17:53:26.433Z,1666029206.433 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-10-17T17:53:26.433Z,1666029206.433 [Startup:StartupSatComms] Stopped
2022-10-17T17:53:26.434Z,1666029206.434 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-10-17T17:53:26.435Z,1666029206.435 [Startup](INFO): Completed Startup
2022-10-17T17:53:26.435Z,1666029206.435 [MissionManager](INFO): Startup is completed.
2022-10-17T17:53:26.435Z,1666029206.435 [MissionManager](INFO): Uninitializing Mission Startup
2022-10-17T17:53:26.435Z,1666029206.435 [Startup] Stopped
2022-10-17T17:53:26.435Z,1666029206.435 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-10-17T17:53:26.435Z,1666029206.435 [Startup:A.GoToSurface] Stopped
2022-10-17T17:53:26.435Z,1666029206.435 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-17T17:53:26.885Z,1666029206.885 [MissionManager](IMPORTANT): Started mission Default
2022-10-17T17:53:26.885Z,1666029206.885 [Default] Running Loop=1
2022-10-17T17:53:26.885Z,1666029206.885 [Default](DEBUG): Aggregate::initialize Default
2022-10-17T17:53:26.886Z,1666029206.886 [Default:B.GoToSurface] Running Loop=1
2022-10-17T17:53:26.886Z,1666029206.886 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-17T17:53:26.907Z,1666029206.907 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-17T17:53:26.908Z,1666029206.908 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-17T17:53:26.908Z,1666029206.908 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-17T17:53:26.908Z,1666029206.908 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-17T17:53:26.909Z,1666029206.909 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-17T17:53:26.909Z,1666029206.909 [Default:A.Wait] Running Loop=1
2022-10-17T17:53:26.909Z,1666029206.909 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-17T17:53:27.148Z,1666029207.148 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0001.lzma.bak
2022-10-17T17:53:27.148Z,1666029207.148 [DataOverHttps](INFO): SBD MOMSN=17246600
2022-10-17T17:53:40.166Z,1666029220.166 [Default:A.Wait](INFO): Done Waiting.
2022-10-17T17:53:40.166Z,1666029220.166 [Default:A.Wait] Stopped
2022-10-17T17:53:40.166Z,1666029220.166 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T17:53:40.867Z,1666029220.867 [Default:CheckIn] Running Loop=1
2022-10-17T17:53:40.874Z,1666029220.874 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T17:53:40.874Z,1666029220.874 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T17:53:41.236Z,1666029221.236 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-10-17T17:55:34.121Z,1666029334.121 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-17T17:55:52.727Z,1666029352.727 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-10-17T17:55:52.727Z,1666029352.727 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T17:55:52.795Z,1666029352.795 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T17:55:53.251Z,1666029353.251 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T17:55:53.251Z,1666029353.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-10-17T17:57:20.371Z,1666029440.371 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2022-10-17T17:57:20.374Z,1666029440.374 [BPC1](INFO): Received data from all battery sticks.
2022-10-17T17:57:27.702Z,1666029447.702 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2022-10-17T17:57:27.702Z,1666029447.702 [RDI_Pathfinder] Communications Fault, FailCount= 1
2022-10-17T17:57:27.702Z,1666029447.702 [RDI_Pathfinder](ERROR): Communications Fault
2022-10-17T17:57:27.802Z,1666029447.802 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2022-10-17T17:57:28.118Z,1666029448.118 [RDI_Pathfinder](INFO): Powering down
2022-10-17T17:57:28.946Z,1666029448.946 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2022-10-17T17:57:28.946Z,1666029448.946 [RDI_Pathfinder] No Fault, FailCount= 1
2022-10-17T17:57:29.277Z,1666029449.277 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-10-17T17:58:41.194Z,1666029521.194 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-17T17:53:40.9Z
2022-10-17T17:58:41.194Z,1666029521.194 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T17:58:41.194Z,1666029521.194 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T17:58:41.604Z,1666029521.604 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-17T17:58:48.806Z,1666029528.806 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20221017T174941/Courier0004.lzma
2022-10-17T17:58:49.808Z,1666029529.808 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0004.lzma.bak
2022-10-17T17:58:49.808Z,1666029529.808 [DataOverHttps](INFO): SBD MOMSN=17246662
2022-10-17T17:58:53.706Z,1666029533.706 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-10-17T17:58:53.706Z,1666029533.706 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T17:58:53.766Z,1666029533.766 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T17:58:54.178Z,1666029534.178 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T17:58:54.178Z,1666029534.178 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-10-17T17:59:05.966Z,1666029545.966 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20221017T174941/Express0005.lzma
2022-10-17T17:59:06.972Z,1666029546.972 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0005.lzma.bak
2022-10-17T17:59:06.972Z,1666029546.972 [DataOverHttps](INFO): SBD MOMSN=17246667
2022-10-17T17:59:08.267Z,1666029548.267 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T17:59:08.268Z,1666029548.268 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T17:59:08.268Z,1666029548.268 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:00:32.513Z,1666029632.513 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-17T18:00:32.513Z,1666029632.513 [NAL9602] Data Fault, FailCount= 1
2022-10-17T18:00:32.513Z,1666029632.513 [NAL9602](ERROR): Data Fault
2022-10-17T18:00:32.655Z,1666029632.655 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-17T18:00:32.925Z,1666029632.925 [NAL9602](INFO): Powering down
2022-10-17T18:00:33.799Z,1666029633.799 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-17T18:00:33.799Z,1666029633.799 [NAL9602] No Fault, FailCount= 1
2022-10-17T18:01:03.220Z,1666029663.220 [NAL9602](INFO): Powering up NAL9602
2022-10-17T18:01:14.125Z,1666029674.125 [NAL9602](INFO): NAL9602 initialized
2022-10-17T18:01:54.548Z,1666029714.548 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-10-17T18:01:54.549Z,1666029714.549 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:01:54.631Z,1666029714.631 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:01:55.047Z,1666029715.047 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:01:55.047Z,1666029715.047 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-10-17T18:04:09.068Z,1666029849.068 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T18:04:09.068Z,1666029849.068 [Default:CheckIn:C.Wait] Stopped
2022-10-17T18:04:09.068Z,1666029849.068 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:04:09.069Z,1666029849.069 [Default:CheckIn:D] Running Loop=1
2022-10-17T18:04:09.504Z,1666029849.504 [Default:CheckIn:D] Stopped
2022-10-17T18:04:09.504Z,1666029849.504 [Default:CheckIn:E] Running Loop=1
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.710306 min 
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn:E] Stopped
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn] Stopped
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn](INFO): Running loop #2
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn] Running Loop=2
2022-10-17T18:04:09.901Z,1666029849.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T18:04:09.902Z,1666029849.902 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T18:04:55.552Z,1666029895.552 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-10-17T18:04:55.552Z,1666029895.552 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:04:55.616Z,1666029895.616 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:04:56.003Z,1666029896.003 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:04:56.003Z,1666029896.003 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-10-17T18:06:52.661Z,1666030012.661 [CommandExec](IMPORTANT): got command failComponent
2022-10-17T18:06:52.662Z,1666030012.662 [CommandExec](IMPORTANT): Failed components:
2022-10-17T18:06:52.667Z,1666030012.667 [CommandExec](IMPORTANT): No failed Components.
2022-10-17T18:06:57.448Z,1666030017.448 [CommandExec](IMPORTANT): got command gfscan
2022-10-17T18:06:57.637Z,1666030017.637 [CBIT](IMPORTANT): Beginning ground fault scan
2022-10-17T18:07:08.534Z,1666030028.534 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.011850
CHAN A1 (24V): 0.001330
CHAN A2 (12V): -0.007438
CHAN A3 (5V): -0.002387
CHAN B0 (3.3V): -0.000039
CHAN B1 (3.15aV): -0.000193
CHAN B2 (3.15bV): 0.000380
CHAN B3 (GND): 0.001323
OPEN: 0.005217
Full Scale: +/- 1 mA
2022-10-17T18:07:56.338Z,1666030076.338 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-10-17T18:07:56.338Z,1666030076.338 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:07:56.405Z,1666030076.405 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:07:56.795Z,1666030076.795 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:07:56.795Z,1666030076.795 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-10-17T18:08:50.844Z,1666030130.844 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-10-17T18:09:10.248Z,1666030150.248 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-17T18:04:09.9Z
2022-10-17T18:09:10.248Z,1666030150.248 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T18:09:10.248Z,1666030150.248 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T18:09:38.657Z,1666030178.657 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20221017T174941/Courier0007.lzma
2022-10-17T18:09:39.659Z,1666030179.659 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0007.lzma.bak
2022-10-17T18:09:39.660Z,1666030179.660 [DataOverHttps](INFO): SBD MOMSN=17246716
2022-10-17T18:09:55.797Z,1666030195.797 [DataOverHttps](INFO): Sending 432 bytes from file Logs/20221017T174941/Express0008.lzma
2022-10-17T18:09:56.799Z,1666030196.799 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0008.lzma.bak
2022-10-17T18:09:56.799Z,1666030196.799 [DataOverHttps](INFO): SBD MOMSN=17246718
2022-10-17T18:09:58.348Z,1666030198.348 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T18:09:58.348Z,1666030198.348 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T18:09:58.348Z,1666030198.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:10:57.370Z,1666030257.370 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-10-17T18:10:57.370Z,1666030257.370 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:10:57.439Z,1666030257.439 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:10:57.845Z,1666030257.845 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:10:57.845Z,1666030257.845 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-10-17T18:11:17.563Z,1666030277.563 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-17T18:11:17.563Z,1666030277.563 [NAL9602] Data Fault, FailCount= 2
2022-10-17T18:11:17.563Z,1666030277.563 [NAL9602](ERROR): Data Fault
2022-10-17T18:11:17.641Z,1666030277.641 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-17T18:11:17.967Z,1666030277.967 [NAL9602](INFO): Powering down
2022-10-17T18:11:18.885Z,1666030278.885 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-17T18:11:18.885Z,1666030278.885 [NAL9602] No Fault, FailCount= 2
2022-10-17T18:11:48.275Z,1666030308.275 [NAL9602](INFO): Powering up NAL9602
2022-10-17T18:11:59.184Z,1666030319.184 [NAL9602](INFO): NAL9602 initialized
2022-10-17T18:13:58.379Z,1666030438.379 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2022-10-17T18:13:58.379Z,1666030438.379 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:13:58.446Z,1666030438.446 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:13:58.845Z,1666030438.845 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:13:58.845Z,1666030438.845 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2022-10-17T18:14:58.983Z,1666030498.983 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T18:14:58.983Z,1666030498.983 [Default:CheckIn:C.Wait] Stopped
2022-10-17T18:14:58.983Z,1666030498.983 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:14:58.983Z,1666030498.983 [Default:CheckIn:D] Running Loop=1
2022-10-17T18:14:59.378Z,1666030499.378 [Default:CheckIn:D] Stopped
2022-10-17T18:14:59.378Z,1666030499.378 [Default:CheckIn:E] Running Loop=1
2022-10-17T18:14:59.777Z,1666030499.777 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.541545 min 
2022-10-17T18:14:59.777Z,1666030499.777 [Default:CheckIn:E] Stopped
2022-10-17T18:14:59.777Z,1666030499.777 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T18:14:59.777Z,1666030499.777 [Default:CheckIn] Stopped
2022-10-17T18:14:59.778Z,1666030499.778 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T18:14:59.778Z,1666030499.778 [Default:CheckIn](INFO): Running loop #3
2022-10-17T18:14:59.778Z,1666030499.778 [Default:CheckIn] Running Loop=3
2022-10-17T18:14:59.778Z,1666030499.778 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T18:14:59.778Z,1666030499.778 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T18:16:59.364Z,1666030619.364 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2022-10-17T18:16:59.364Z,1666030619.364 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-17T18:16:59.423Z,1666030619.423 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-17T18:16:59.838Z,1666030619.838 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-17T18:16:59.838Z,1666030619.838 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2022-10-17T18:18:10.052Z,1666030690.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181808.00,A,3648.16528,N,12147.27643,W,0.292,0.00,171022,,,A*7E
2022-10-17T18:18:10.056Z,1666030690.056 [NAL9602](INFO): GPS fix at 20221017T181808: (36.802755, -121.787941)
2022-10-17T18:18:10.075Z,1666030690.075 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T18:18:10.075Z,1666030690.075 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T18:18:12.776Z,1666030692.776 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-10-17T18:18:21.241Z,1666030701.241 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20221017T174941/Courier0010.lzma
2022-10-17T18:18:22.243Z,1666030702.243 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0010.lzma.bak
2022-10-17T18:18:22.243Z,1666030702.243 [DataOverHttps](INFO): SBD MOMSN=17246759
2022-10-17T18:18:40.285Z,1666030720.285 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20221017T174941/Express0011.lzma
2022-10-17T18:18:41.287Z,1666030721.287 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0011.lzma.bak
2022-10-17T18:18:41.287Z,1666030721.287 [DataOverHttps](INFO): SBD MOMSN=17246762
2022-10-17T18:18:42.650Z,1666030722.650 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T18:18:42.691Z,1666030722.691 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T18:18:42.691Z,1666030722.691 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T18:18:42.691Z,1666030722.691 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:21:48.547Z,1666030908.547 [DataOverHttps](IMPORTANT): SBD MTMSN=20221017T182147
2022-10-17T18:21:56.533Z,1666030916.533 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-10-17T18:21:56.676Z,1666030916.676 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-17T18:21:56.679Z,1666030916.679 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-17T18:21:56.748Z,1666030916.748 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-10-17T18:21:56.753Z,1666030916.753 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-10-17T18:21:56.756Z,1666030916.756 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-10-17T18:21:56.759Z,1666030916.759 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-10-17T18:21:56.762Z,1666030916.762 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-10-17T18:21:56.764Z,1666030916.764 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-10-17T18:21:56.788Z,1666030916.788 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-10-17T18:21:56.791Z,1666030916.791 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-10-17T18:21:56.802Z,1666030916.802 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-10-17T18:21:56.805Z,1666030916.805 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-10-17T18:21:56.812Z,1666030916.812 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-10-17T18:21:56.815Z,1666030916.815 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-10-17T18:21:56.826Z,1666030916.826 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-10-17T18:21:56.829Z,1666030916.829 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-10-17T18:21:56.833Z,1666030916.833 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-10-17T18:21:57.249Z,1666030917.249 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-10-17T18:21:57.252Z,1666030917.252 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-10-17T18:21:57.255Z,1666030917.255 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-10-17T18:21:57.274Z,1666030917.274 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-10-17T18:21:57.277Z,1666030917.277 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-10-17T18:21:57.284Z,1666030917.284 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-10-17T18:21:57.287Z,1666030917.287 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-10-17T18:21:57.298Z,1666030917.298 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-10-17T18:21:57.300Z,1666030917.300 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-10-17T18:21:57.308Z,1666030917.308 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-10-17T18:21:57.311Z,1666030917.311 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-10-17T18:21:57.326Z,1666030917.326 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-10-17T18:21:57.328Z,1666030917.328 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-10-17T18:21:57.335Z,1666030917.335 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-10-17T18:21:57.339Z,1666030917.339 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-10-17T18:21:57.350Z,1666030917.350 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-10-17T18:21:57.355Z,1666030917.355 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-10-17T18:21:57.367Z,1666030917.367 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-10-17T18:21:57.400Z,1666030917.400 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-10-17T18:21:57.419Z,1666030917.419 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-10-17T18:21:57.428Z,1666030917.428 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 1 bool
2022-10-17T18:21:57.444Z,1666030917.444 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-10-17T18:21:57.451Z,1666030917.451 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-10-17T18:21:57.455Z,1666030917.455 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-10-17T18:21:57.470Z,1666030917.470 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-10-17T18:21:57.473Z,1666030917.473 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-10-17T18:21:57.504Z,1666030917.504 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-10-17T18:21:57.511Z,1666030917.511 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-10-17T18:21:57.518Z,1666030917.518 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-10-17T18:21:57.524Z,1666030917.524 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-10-17T18:21:57.542Z,1666030917.542 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-10-17T18:21:57.559Z,1666030917.559 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-10-17T18:21:57.566Z,1666030917.566 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-10-17T18:21:57.574Z,1666030917.574 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-10-17T18:21:57.577Z,1666030917.577 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-10-17T18:21:57.584Z,1666030917.584 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-10-17T18:21:57.602Z,1666030917.602 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-10-17T18:21:57.631Z,1666030917.631 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-10-17T18:21:57.661Z,1666030917.661 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-10-17T18:21:57.675Z,1666030917.675 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-10-17T18:21:57.682Z,1666030917.682 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-10-17T18:21:57.685Z,1666030917.685 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-10-17T18:21:57.696Z,1666030917.696 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-10-17T18:21:57.716Z,1666030917.716 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-10-17T18:21:57.728Z,1666030917.728 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-10-17T18:21:57.737Z,1666030917.737 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-10-17T18:21:57.744Z,1666030917.744 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-10-17T18:21:57.766Z,1666030917.766 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-10-17T18:21:57.769Z,1666030917.769 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-10-17T18:21:57.808Z,1666030917.808 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-10-17T18:21:57.815Z,1666030917.815 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-10-17T18:21:57.823Z,1666030917.823 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-10-17T18:21:57.838Z,1666030917.838 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-10-17T18:21:57.846Z,1666030917.846 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-10-17T18:21:57.849Z,1666030917.849 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-10-17T18:21:57.868Z,1666030917.868 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-10-17T18:21:57.871Z,1666030917.871 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-10-17T18:21:57.875Z,1666030917.875 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-10-17T18:21:57.898Z,1666030917.898 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-10-17T18:21:57.904Z,1666030917.904 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-10-17T18:21:57.908Z,1666030917.908 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-10-17T18:21:57.912Z,1666030917.912 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-10-17T18:21:57.927Z,1666030917.927 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-10-17T18:21:57.936Z,1666030917.936 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-10-17T18:21:57.944Z,1666030917.944 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-10-17T18:21:58.014Z,1666030918.014 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-17T18:21:58.032Z,1666030918.032 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-17T18:21:58.065Z,1666030918.065 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-17T18:21:58.084Z,1666030918.084 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-17T18:21:58.104Z,1666030918.104 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-17T18:21:58.142Z,1666030918.142 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-17T18:21:58.165Z,1666030918.165 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-10-17T18:21:58.216Z,1666030918.216 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-10-17T18:21:58.257Z,1666030918.257 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-10-17T18:21:58.479Z,1666030918.479 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-10-17T18:21:58.487Z,1666030918.487 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-10-17T18:21:58.494Z,1666030918.494 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-10-17T18:21:58.497Z,1666030918.497 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-10-17T18:21:58.504Z,1666030918.504 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-10-17T18:21:58.508Z,1666030918.508 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-10-17T18:21:58.519Z,1666030918.519 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-10-17T18:21:58.526Z,1666030918.526 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-10-17T18:21:58.532Z,1666030918.532 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-10-17T18:21:58.536Z,1666030918.536 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-10-17T18:21:58.543Z,1666030918.543 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-10-17T18:21:58.548Z,1666030918.548 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-10-17T18:21:58.559Z,1666030918.559 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-10-17T18:21:58.566Z,1666030918.566 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-10-17T18:21:58.627Z,1666030918.627 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-10-17T18:21:58.655Z,1666030918.655 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-10-17T18:21:58.665Z,1666030918.665 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-10-17T18:21:58.710Z,1666030918.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-10-17T18:21:58.719Z,1666030918.719 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-10-17T18:21:58.736Z,1666030918.736 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-10-17T18:21:58.756Z,1666030918.756 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-10-17T18:21:58.763Z,1666030918.763 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-10-17T18:21:58.771Z,1666030918.771 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-10-17T18:21:58.791Z,1666030918.791 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-10-17T18:21:58.808Z,1666030918.808 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-10-17T18:21:58.852Z,1666030918.852 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-10-17T18:21:58.863Z,1666030918.863 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-10-17T18:21:58.865Z,1666030918.865 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-10-17T18:21:58.871Z,1666030918.871 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-10-17T18:21:58.873Z,1666030918.873 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-10-17T18:21:58.883Z,1666030918.883 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-10-17T18:21:58.885Z,1666030918.885 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-10-17T18:21:58.891Z,1666030918.891 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-10-17T18:21:58.911Z,1666030918.911 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-10-17T18:21:58.922Z,1666030918.922 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-10-17T18:21:58.974Z,1666030918.974 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="ballast_and_trim">

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

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

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

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

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

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

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

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

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

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

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

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

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

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

    <Timeout Duration="MissionTimeout"/>

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

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

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

        <Aggregate Id="Depth1">

            <Sequence/>

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

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

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

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

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

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

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

        <Sequence/>

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

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

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

    </Aggregate>

</Mission>


2022-10-17T18:21:58.982Z,1666030918.982 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-10-17T18:21:59.028Z,1666030919.028 [Default] Stopped
2022-10-17T18:21:59.028Z,1666030919.028 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-17T18:21:59.029Z,1666030919.029 [Default:B.GoToSurface] Stopped
2022-10-17T18:21:59.029Z,1666030919.029 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-17T18:21:59.029Z,1666030919.029 [Default:CheckIn] Stopped
2022-10-17T18:21:59.029Z,1666030919.029 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T18:21:59.029Z,1666030919.029 [Default:CheckIn:C.Wait] Stopped
2022-10-17T18:21:59.037Z,1666030919.037 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:21:59.037Z,1666030919.037 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:A] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:B] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:C] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:D] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:E] Running Loop=1
2022-10-17T18:21:59.038Z,1666030919.038 [ballast_and_trim:Science:F] Running Loop=1
2022-10-17T18:21:59.039Z,1666030919.039 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-10-17T18:21:59.039Z,1666030919.039 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-10-17T18:21:59.039Z,1666030919.039 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-10-17T18:21:59.039Z,1666030919.039 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-10-17T18:21:59.039Z,1666030919.039 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-17T18:21:59.041Z,1666030919.041 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-10-17T18:21:59.041Z,1666030919.041 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-10-17T18:21:59.045Z,1666030919.045 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-17T18:21:59.045Z,1666030919.045 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-17T18:21:59.046Z,1666030919.046 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-10-17T18:21:59.046Z,1666030919.046 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-10-17T18:21:59.046Z,1666030919.046 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-10-17T18:21:59.046Z,1666030919.046 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-17T18:21:59.051Z,1666030919.051 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-10-17T18:21:59.051Z,1666030919.051 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-10-17T18:21:59.051Z,1666030919.051 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-10-17T18:21:59.051Z,1666030919.051 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-17T18:21:59.057Z,1666030919.057 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-10-17T18:21:59.058Z,1666030919.058 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-17T18:21:59.060Z,1666030919.060 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-10-17T18:21:59.060Z,1666030919.060 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-10-17T18:21:59.061Z,1666030919.061 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-10-17T18:21:59.061Z,1666030919.061 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-10-17T18:21:59.063Z,1666030919.063 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-10-17T18:21:59.063Z,1666030919.063 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-10-17T18:21:59.063Z,1666030919.063 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-10-17T18:21:59.063Z,1666030919.063 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-10-17T18:21:59.063Z,1666030919.063 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-10-17T18:21:59.064Z,1666030919.064 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-17T18:21:59.065Z,1666030919.065 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-10-17T18:21:59.074Z,1666030919.074 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-10-17T18:21:59.074Z,1666030919.074 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-10-17T18:21:59.074Z,1666030919.074 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-17T18:21:59.074Z,1666030919.074 [ballast_and_trim:Science] Running Loop=1
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-10-17T18:21:59.075Z,1666030919.075 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-10-17T18:21:59.076Z,1666030919.076 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-10-17T18:21:59.077Z,1666030919.077 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-17T18:21:59.077Z,1666030919.077 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-10-17T18:21:59.077Z,1666030919.077 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-10-17T18:21:59.077Z,1666030919.077 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-10-17T18:21:59.077Z,1666030919.077 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-17T18:21:59.081Z,1666030919.081 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-10-17T18:21:59.081Z,1666030919.081 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-10-17T18:21:59.081Z,1666030919.081 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-10-17T18:21:59.081Z,1666030919.081 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:Read_Oil] Stopped
2022-10-17T18:21:59.082Z,1666030919.082 [ballast_and_trim:Science:F] Running Loop=1
2022-10-17T18:21:59.085Z,1666030919.085 [ballast_and_trim:Science:F](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.average_bioluminescence
2022-10-17T18:21:59.085Z,1666030919.085 [ballast_and_trim:Science:E] Running Loop=1
2022-10-17T18:21:59.086Z,1666030919.086 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-10-17T18:21:59.086Z,1666030919.086 [ballast_and_trim:Science:D] Stopped
2022-10-17T18:21:59.086Z,1666030919.086 [ballast_and_trim:Science:C] Running Loop=1
2022-10-17T18:21:59.087Z,1666030919.087 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-10-17T18:21:59.087Z,1666030919.087 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-10-17T18:21:59.088Z,1666030919.088 [ballast_and_trim:Science:B] Running Loop=1
2022-10-17T18:21:59.088Z,1666030919.088 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-10-17T18:21:59.089Z,1666030919.089 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-10-17T18:21:59.089Z,1666030919.089 [ballast_and_trim:Science:A] Stopped
2022-10-17T18:21:59.291Z,1666030919.291 [WetLabsBB2FL](INFO): Powering up
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-10-17T18:21:59.443Z,1666030919.443 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-10-17T18:21:59.444Z,1666030919.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-10-17T18:21:59.444Z,1666030919.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-10-17T18:21:59.458Z,1666030919.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-10-17T18:21:59.459Z,1666030919.459 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-17T18:21:59.460Z,1666030919.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-10-17T18:21:59.460Z,1666030919.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-10-17T18:21:59.460Z,1666030919.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-10-17T18:21:59.460Z,1666030919.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-10-17T18:21:59.460Z,1666030919.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-10-17T18:21:59.461Z,1666030919.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-10-17T18:21:59.519Z,1666030919.519 [WetLabsUBAT](INFO): Powering up
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-10-17T18:21:59.875Z,1666030919.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-10-17T18:22:00.236Z,1666030920.236 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-10-17T18:22:00.236Z,1666030920.236 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-10-17T18:22:00.236Z,1666030920.236 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:22:00.237Z,1666030920.237 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-17T18:22:00.237Z,1666030920.237 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-10-17T18:22:00.237Z,1666030920.237 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-10-17T18:22:00.237Z,1666030920.237 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-10-17T18:22:00.241Z,1666030920.241 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-17T18:22:00.241Z,1666030920.241 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-10-17T18:22:00.241Z,1666030920.241 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-10-17T18:22:00.242Z,1666030920.242 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-10-17T18:22:00.646Z,1666030920.646 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-10-17T18:22:00.647Z,1666030920.647 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-10-17T18:22:00.647Z,1666030920.647 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-10-17T18:22:00.647Z,1666030920.647 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-10-17T18:22:00.647Z,1666030920.647 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-10-17T18:22:02.239Z,1666030922.239 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-10-17T18:22:09.708Z,1666030929.708 [WetLabsUBAT](FAULT): UBAT flow rate is below the specified threshold of 0.05 l/s.
2022-10-17T18:22:15.806Z,1666030935.806 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-10-17T18:22:18.009Z,1666030938.009 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:23:30.416Z,1666031010.416 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2022-10-17T18:23:44.472Z,1666031024.472 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.179432
2022-10-17T18:24:40.695Z,1666031080.695 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T18:24:51.987Z,1666031091.987 [Radio_Surface](INFO): Powering down
2022-10-17T18:25:15.836Z,1666031115.836 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T18:25:16.326Z,1666031116.326 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2022-10-17T18:25:16.849Z,1666031116.849 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-10-17T18:26:10.467Z,1666031170.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-10-17T18:26:10.468Z,1666031170.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-17T18:26:10.468Z,1666031170.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-10-17T18:26:10.468Z,1666031170.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-10-17T18:26:10.468Z,1666031170.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-10-17T18:26:10.468Z,1666031170.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-10-17T18:26:10.469Z,1666031170.469 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-10-17T18:26:10.470Z,1666031170.470 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-10-17T18:26:10.470Z,1666031170.470 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-10-17T18:26:10.470Z,1666031170.470 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.031073 m 
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-10-17T18:26:10.878Z,1666031170.878 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-10-17T18:27:16.320Z,1666031236.320 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-10-17T18:30:49.331Z,1666031449.331 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-10-17T18:32:08.012Z,1666031528.012 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:36:11.715Z,1666031771.715 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-10-17T18:36:11.715Z,1666031771.715 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-10-17T18:36:11.715Z,1666031771.715 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:36:11.716Z,1666031771.716 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-10-17T18:36:12.077Z,1666031772.077 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 6.974410 m 
2022-10-17T18:36:12.078Z,1666031772.078 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-10-17T18:36:12.078Z,1666031772.078 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-10-17T18:36:12.078Z,1666031772.078 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-10-17T18:42:48.801Z,1666032168.801 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-10-17T18:46:18.881Z,1666032378.881 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:49:02.481Z,1666032542.481 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-10-17T18:49:39.751Z,1666032579.751 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude
2022-10-17T18:52:09.158Z,1666032729.158 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:57:26.800Z,1666033046.800 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-10-17T18:57:48.538Z,1666033068.538 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 21.60 minutes.
2022-10-17T18:57:48.540Z,1666033068.540 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 220.217773 +/- 14.997093 cc (conf. level 99.90%, sigma: 26.105115 cc).
2022-10-17T18:57:48.541Z,1666033068.541 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 6.834666 +/- 0.225941 mm (conf. level 99.90%, sigma: 0.393290 mm).
2022-10-17T18:57:48.541Z,1666033068.541 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 220.217773 cc buoyancy neutral and 6.834666 mm mass default
2022-10-17T18:57:48.548Z,1666033068.548 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-10-17T18:57:48.549Z,1666033068.549 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-10-17T18:57:48.549Z,1666033068.549 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-10-17T18:57:48.549Z,1666033068.549 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-10-17T18:57:48.549Z,1666033068.549 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-10-17T18:57:48.549Z,1666033068.549 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.verbosity=2 count;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express none _.adinos;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express none _.aother;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-10-17T18:57:48.550Z,1666033068.550 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-10-17T18:57:48.551Z,1666033068.551 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-10-17T18:57:48.551Z,1666033068.551 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-10-17T18:57:48.579Z,1666033068.579 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=220.217773 cubic_centimeter;

2022-10-17T18:57:48.581Z,1666033068.581 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=6.834666 millimeter;

2022-10-17T18:57:48.582Z,1666033068.582 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-10-17T18:57:48.582Z,1666033068.582 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-10-17T18:57:48.587Z,1666033068.587 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-17T18:57:48.587Z,1666033068.587 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-10-17T18:57:48.588Z,1666033068.588 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-10-17T18:57:48.588Z,1666033068.588 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-10-17T18:57:48.588Z,1666033068.588 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-10-17T18:57:48.588Z,1666033068.588 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-10-17T18:57:48.589Z,1666033068.589 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-10-17T18:57:48.949Z,1666033068.949 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2022-10-17T18:57:48.950Z,1666033068.950 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-10-17T18:57:48.950Z,1666033068.950 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-10-17T18:57:49.371Z,1666033069.371 [ballast_and_trim:Float_Up] Running Loop=1
2022-10-17T18:57:49.372Z,1666033069.372 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2022-10-17T18:57:49.372Z,1666033069.372 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-10-17T18:57:49.372Z,1666033069.372 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-10-17T18:57:49.372Z,1666033069.372 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2022-10-17T18:57:49.372Z,1666033069.372 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:57:49.753Z,1666033069.753 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-10-17T18:59:04.522Z,1666033144.522 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:59:09.402Z,1666033149.402 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-10-17T18:59:43.091Z,1666033183.091 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2022-10-17T18:59:43.701Z,1666033183.701 [ballast_and_trim:Float_Up] Stopped
2022-10-17T18:59:43.701Z,1666033183.701 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2022-10-17T18:59:43.701Z,1666033183.701 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2022-10-17T18:59:43.701Z,1666033183.701 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-10-17T18:59:43.702Z,1666033183.702 [ballast_and_trim:Float_Up:B.Wait] Stopped
2022-10-17T18:59:43.702Z,1666033183.702 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-10-17T18:59:43.712Z,1666033183.712 [MissionManager](INFO): ballast_and_trim is completed.
2022-10-17T18:59:43.712Z,1666033183.712 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim] Stopped
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim:Science] Stopped
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim:Science:B] Stopped
2022-10-17T18:59:43.712Z,1666033183.712 [ballast_and_trim:Science:C] Stopped
2022-10-17T18:59:43.713Z,1666033183.713 [ballast_and_trim:Science:E] Stopped
2022-10-17T18:59:43.713Z,1666033183.713 [ballast_and_trim:Science:F] Stopped
2022-10-17T18:59:43.713Z,1666033183.713 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-10-17T18:59:43.713Z,1666033183.713 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-10-17T18:59:43.713Z,1666033183.713 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-10-17T18:59:43.923Z,1666033183.923 [WetLabsBB2FL](INFO): Powering down
2022-10-17T18:59:44.128Z,1666033184.128 [MissionManager](IMPORTANT): Started mission Default
2022-10-17T18:59:44.128Z,1666033184.128 [Default] Running Loop=1
2022-10-17T18:59:44.128Z,1666033184.128 [Default](DEBUG): Aggregate::initialize Default
2022-10-17T18:59:44.128Z,1666033184.128 [Default:B.GoToSurface] Running Loop=1
2022-10-17T18:59:44.128Z,1666033184.128 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-17T18:59:44.129Z,1666033184.129 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-17T18:59:44.129Z,1666033184.129 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-17T18:59:44.129Z,1666033184.129 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-17T18:59:44.130Z,1666033184.130 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-17T18:59:44.130Z,1666033184.130 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-17T18:59:44.131Z,1666033184.131 [Default:A.Wait] Running Loop=1
2022-10-17T18:59:44.135Z,1666033184.135 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-17T18:59:44.207Z,1666033184.207 [WetLabsUBAT](INFO): Powering down
2022-10-17T18:59:44.405Z,1666033184.405 [Radio_Surface](INFO): Powering up
2022-10-17T18:59:50.395Z,1666033190.395 [DataOverHttps](INFO): Radio surface powered ON.
2022-10-17T18:59:57.443Z,1666033197.443 [Default:A.Wait](INFO): Done Waiting.
2022-10-17T18:59:57.444Z,1666033197.444 [Default:A.Wait] Stopped
2022-10-17T18:59:57.444Z,1666033197.444 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T18:59:57.815Z,1666033197.815 [Default:CheckIn] Running Loop=1
2022-10-17T18:59:57.815Z,1666033197.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T18:59:57.816Z,1666033197.816 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:00:20.515Z,1666033220.515 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:00:55.655Z,1666033255.655 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:01:13.762Z,1666033273.762 [NAL9602](INFO): SBD MO Status=0, MOMSN=21430, MT Status=0, MTMSN=0
2022-10-17T19:01:13.762Z,1666033273.762 [NAL9602](INFO): No messages in MT queue
2022-10-17T19:01:14.970Z,1666033274.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190112.00,A,3648.15739,N,12147.27981,W,0.719,162.72,171022,,,A*7A
2022-10-17T19:01:14.972Z,1666033274.972 [NAL9602](INFO): GPS fix at 20221017T190112: (36.802623, -121.787997)
2022-10-17T19:01:14.983Z,1666033274.983 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:01:14.984Z,1666033274.984 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:01:30.803Z,1666033290.803 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:01:36.926Z,1666033296.926 [NAL9602](INFO): SBD MO Status=2, MOMSN=21431, MT Status=2, MTMSN=0
2022-10-17T19:01:36.926Z,1666033296.926 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:02:05.944Z,1666033325.944 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:02:10.942Z,1666033330.942 [NAL9602](INFO): SBD MO Status=2, MOMSN=21431, MT Status=2, MTMSN=0
2022-10-17T19:02:10.943Z,1666033330.943 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:02:27.198Z,1666033347.198 [NAL9602](INFO): SBD MO Status=2, MOMSN=21431, MT Status=2, MTMSN=0
2022-10-17T19:02:27.198Z,1666033347.198 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:02:41.083Z,1666033361.083 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:03:14.388Z,1666033394.388 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003442
2022-10-17T19:03:21.695Z,1666033401.695 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221017T174941/Courier0013.lzma
2022-10-17T19:03:22.697Z,1666033402.697 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0013.lzma.bak
2022-10-17T19:03:22.697Z,1666033402.697 [DataOverHttps](INFO): SBD MOMSN=17246859
2022-10-17T19:03:30.782Z,1666033410.782 [NAL9602](INFO): SBD MO Status=2, MOMSN=21431, MT Status=2, MTMSN=0
2022-10-17T19:03:30.783Z,1666033410.783 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:03:40.194Z,1666033420.194 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221017T174941/Courier0016.lzma
2022-10-17T19:03:41.197Z,1666033421.197 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0016.lzma.bak
2022-10-17T19:03:41.197Z,1666033421.197 [DataOverHttps](INFO): SBD MOMSN=17246863
2022-10-17T19:03:57.953Z,1666033437.953 [DataOverHttps](INFO): Sending 1381 bytes from file Logs/20221017T174941/Express0014.lzma
2022-10-17T19:03:58.953Z,1666033438.953 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0014.lzma.bak
2022-10-17T19:03:58.953Z,1666033438.953 [DataOverHttps](INFO): SBD MOMSN=17246865
2022-10-17T19:04:01.493Z,1666033441.493 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T19:04:21.355Z,1666033461.355 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221017T174941/Express0017.lzma
2022-10-17T19:04:22.357Z,1666033462.357 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0017.lzma.bak
2022-10-17T19:04:22.357Z,1666033462.357 [DataOverHttps](INFO): SBD MOMSN=17246895
2022-10-17T19:04:23.823Z,1666033463.823 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:04:23.824Z,1666033463.824 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:04:23.824Z,1666033463.824 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:04:33.904Z,1666033473.904 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-10-17T19:04:46.844Z,1666033486.844 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2022-10-17T19:04:46.847Z,1666033486.847 [BPC1](INFO): Received data from all battery sticks.
2022-10-17T19:09:24.391Z,1666033764.391 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:09:24.391Z,1666033764.391 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:09:24.391Z,1666033764.391 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:09:24.392Z,1666033764.392 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:09:24.844Z,1666033764.844 [Default:CheckIn:D] Stopped
2022-10-17T19:09:24.844Z,1666033764.844 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.678598 min 
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn:E] Stopped
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn] Stopped
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn](INFO): Running loop #2
2022-10-17T19:09:25.194Z,1666033765.194 [Default:CheckIn] Running Loop=2
2022-10-17T19:09:25.195Z,1666033765.195 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:09:25.195Z,1666033765.195 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:09:27.210Z,1666033767.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190925.00,A,3648.16154,N,12147.28277,W,0.097,162.72,171022,,,A*74
2022-10-17T19:09:27.213Z,1666033767.213 [NAL9602](INFO): GPS fix at 20221017T190925: (36.802692, -121.788046)
2022-10-17T19:09:27.225Z,1666033767.225 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:09:27.225Z,1666033767.225 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:09:34.975Z,1666033774.975 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20221017T174941/Courier0019.lzma
2022-10-17T19:09:35.977Z,1666033775.977 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0019.lzma.bak
2022-10-17T19:09:35.977Z,1666033775.977 [DataOverHttps](INFO): SBD MOMSN=17246905
2022-10-17T19:09:52.667Z,1666033792.667 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20221017T174941/Express0020.lzma
2022-10-17T19:09:53.669Z,1666033793.669 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0020.lzma.bak
2022-10-17T19:09:53.669Z,1666033793.669 [DataOverHttps](INFO): SBD MOMSN=17246916
2022-10-17T19:09:55.142Z,1666033795.142 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:09:55.142Z,1666033795.142 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:09:55.142Z,1666033795.142 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:10:03.216Z,1666033803.216 [NAL9602](INFO): SBD MO Status=2, MOMSN=21431, MT Status=2, MTMSN=0
2022-10-17T19:10:03.217Z,1666033803.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:10:14.917Z,1666033814.917 [NAL9602](INFO): SBD MO Status=1, MOMSN=21431, MT Status=0, MTMSN=0
2022-10-17T19:10:14.917Z,1666033814.917 [NAL9602](INFO): No messages in MT queue
2022-10-17T19:10:45.612Z,1666033845.612 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T19:14:55.804Z,1666034095.804 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:14:55.804Z,1666034095.804 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:14:55.804Z,1666034095.804 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:14:55.805Z,1666034095.805 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:14:56.178Z,1666034096.178 [Default:CheckIn:D] Stopped
2022-10-17T19:14:56.179Z,1666034096.179 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.200836 min 
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn:E] Stopped
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn] Stopped
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn](INFO): Running loop #3
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn] Running Loop=3
2022-10-17T19:14:56.585Z,1666034096.585 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:14:56.586Z,1666034096.586 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:14:58.590Z,1666034098.590 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191456.00,A,3648.16330,N,12147.28406,W,0.194,219.37,171022,,,D*75
2022-10-17T19:14:58.592Z,1666034098.592 [NAL9602](INFO): GPS fix at 20221017T191456: (36.802722, -121.788068)
2022-10-17T19:14:58.636Z,1666034098.636 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:14:58.636Z,1666034098.636 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:15:06.702Z,1666034106.702 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221017T174941/Courier0022.lzma
2022-10-17T19:15:07.705Z,1666034107.705 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0022.lzma.bak
2022-10-17T19:15:07.705Z,1666034107.705 [DataOverHttps](INFO): SBD MOMSN=17246936
2022-10-17T19:15:24.431Z,1666034124.431 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20221017T174941/Express0023.lzma
2022-10-17T19:15:25.433Z,1666034125.433 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0023.lzma.bak
2022-10-17T19:15:25.433Z,1666034125.433 [DataOverHttps](INFO): SBD MOMSN=17246939
2022-10-17T19:15:26.890Z,1666034126.890 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:15:26.890Z,1666034126.890 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:15:26.890Z,1666034126.890 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:18:29.962Z,1666034309.962 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:18:29.962Z,1666034309.962 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:18:52.590Z,1666034332.590 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:18:52.590Z,1666034332.590 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:20:00.856Z,1666034400.856 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-17T19:20:27.532Z,1666034427.532 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:20:27.532Z,1666034427.532 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:20:27.532Z,1666034427.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:20:27.533Z,1666034427.533 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:20:27.950Z,1666034427.950 [Default:CheckIn:D] Stopped
2022-10-17T19:20:27.950Z,1666034427.950 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:20:28.343Z,1666034428.343 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.730361 min 
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn:E] Stopped
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn] Stopped
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn](INFO): Running loop #4
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn] Running Loop=4
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:20:28.344Z,1666034428.344 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:20:30.345Z,1666034430.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192028.00,A,3648.16465,N,12147.28692,W,0.136,219.37,171022,,,D*7B
2022-10-17T19:20:30.347Z,1666034430.347 [NAL9602](INFO): GPS fix at 20221017T192028: (36.802744, -121.788115)
2022-10-17T19:20:30.400Z,1666034430.400 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:20:30.400Z,1666034430.400 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:20:37.718Z,1666034437.718 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221017T174941/Courier0025.lzma
2022-10-17T19:20:38.721Z,1666034438.721 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0025.lzma.bak
2022-10-17T19:20:38.721Z,1666034438.721 [DataOverHttps](INFO): SBD MOMSN=17246944
2022-10-17T19:20:55.511Z,1666034455.511 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20221017T174941/Express0026.lzma
2022-10-17T19:20:56.513Z,1666034456.513 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0026.lzma.bak
2022-10-17T19:20:56.513Z,1666034456.513 [DataOverHttps](INFO): SBD MOMSN=17246947
2022-10-17T19:20:57.830Z,1666034457.830 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:20:57.831Z,1666034457.831 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:20:57.831Z,1666034457.831 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:21:02.668Z,1666034462.668 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T19:25:58.459Z,1666034758.459 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:25:58.459Z,1666034758.459 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:25:58.460Z,1666034758.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:25:58.460Z,1666034758.460 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:25:58.902Z,1666034758.902 [Default:CheckIn:D] Stopped
2022-10-17T19:25:58.902Z,1666034758.902 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:25:59.282Z,1666034759.282 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.246228 min 
2022-10-17T19:25:59.282Z,1666034759.282 [Default:CheckIn:E] Stopped
2022-10-17T19:25:59.282Z,1666034759.282 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn] Stopped
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn](INFO): Running loop #5
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn] Running Loop=5
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:25:59.283Z,1666034759.283 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:26:01.262Z,1666034761.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192559.00,A,3648.16473,N,12147.28432,W,0.019,87.29,171022,,,D*41
2022-10-17T19:26:01.265Z,1666034761.265 [NAL9602](INFO): GPS fix at 20221017T192559: (36.802746, -121.788072)
2022-10-17T19:26:01.284Z,1666034761.284 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:26:01.285Z,1666034761.285 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:26:13.183Z,1666034773.183 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221017T174941/Courier0028.lzma
2022-10-17T19:26:14.185Z,1666034774.185 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0028.lzma.bak
2022-10-17T19:26:14.185Z,1666034774.185 [DataOverHttps](INFO): SBD MOMSN=17246964
2022-10-17T19:26:30.891Z,1666034790.891 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20221017T174941/Express0029.lzma
2022-10-17T19:26:31.893Z,1666034791.893 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0029.lzma.bak
2022-10-17T19:26:31.893Z,1666034791.893 [DataOverHttps](INFO): SBD MOMSN=17246967
2022-10-17T19:26:32.034Z,1666034792.034 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-17T19:26:32.111Z,1666034792.111 [NAL9602](ERROR): received: 
+CSQ:1

OK432, 2, 0, 0, 0

OK
2022-10-17T19:26:33.663Z,1666034793.663 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:26:33.664Z,1666034793.664 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:26:33.664Z,1666034793.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:27:23.340Z,1666034843.340 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:27:23.340Z,1666034843.340 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:28:10.210Z,1666034890.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:28:10.210Z,1666034890.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:28:41.726Z,1666034921.726 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:28:41.726Z,1666034921.726 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:29:11.210Z,1666034951.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=21432, MT Status=2, MTMSN=0
2022-10-17T19:29:11.210Z,1666034951.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-10-17T19:29:23.739Z,1666034963.739 [NAL9602](INFO): SBD MO Status=1, MOMSN=21432, MT Status=0, MTMSN=0
2022-10-17T19:29:23.739Z,1666034963.739 [NAL9602](INFO): No messages in MT queue
2022-10-17T19:29:54.437Z,1666034994.437 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T19:31:34.258Z,1666035094.258 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:31:34.258Z,1666035094.258 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:31:34.258Z,1666035094.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:31:34.259Z,1666035094.259 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:31:34.659Z,1666035094.659 [Default:CheckIn:D] Stopped
2022-10-17T19:31:34.659Z,1666035094.659 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:31:35.064Z,1666035095.064 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.842175 min 
2022-10-17T19:31:35.064Z,1666035095.064 [Default:CheckIn:E] Stopped
2022-10-17T19:31:35.064Z,1666035095.064 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn] Stopped
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn](INFO): Running loop #6
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn] Running Loop=6
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:31:35.065Z,1666035095.065 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:31:37.078Z,1666035097.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193134.00,A,3648.17369,N,12147.27695,W,0.428,18.79,171022,,,D*47
2022-10-17T19:31:37.090Z,1666035097.090 [NAL9602](INFO): GPS fix at 20221017T193134: (36.802895, -121.787949)
2022-10-17T19:31:37.101Z,1666035097.101 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:31:37.102Z,1666035097.102 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:31:47.791Z,1666035107.791 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221017T174941/Courier0031.lzma
2022-10-17T19:31:48.793Z,1666035108.793 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0031.lzma.bak
2022-10-17T19:31:48.793Z,1666035108.793 [DataOverHttps](INFO): SBD MOMSN=17247045
2022-10-17T19:32:28.687Z,1666035148.687 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-10-17T19:32:57.804Z,1666035177.804 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239414
2022-10-17T19:33:06.564Z,1666035186.564 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003461
2022-10-17T19:33:14.211Z,1666035194.211 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221017T174941/Express0032.lzma
2022-10-17T19:33:15.214Z,1666035195.214 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0032.lzma.bak
2022-10-17T19:33:15.214Z,1666035195.214 [DataOverHttps](INFO): SBD MOMSN=17247053
2022-10-17T19:33:16.491Z,1666035196.491 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:33:16.491Z,1666035196.491 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:33:16.491Z,1666035196.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:36:38.865Z,1666035398.865 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-17T19:37:09.564Z,1666035429.564 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-17T19:38:17.047Z,1666035497.047 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-17T19:38:17.047Z,1666035497.047 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:38:17.047Z,1666035497.047 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:38:17.047Z,1666035497.047 [Default:CheckIn:D] Running Loop=1
2022-10-17T19:38:17.456Z,1666035497.456 [Default:CheckIn:D] Stopped
2022-10-17T19:38:17.457Z,1666035497.457 [Default:CheckIn:E] Running Loop=1
2022-10-17T19:38:17.882Z,1666035497.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.555469 min 
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn:E] Stopped
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn] Stopped
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn](INFO): Running loop #7
2022-10-17T19:38:17.883Z,1666035497.883 [Default:CheckIn] Running Loop=7
2022-10-17T19:38:17.884Z,1666035497.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-17T19:38:17.884Z,1666035497.884 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-17T19:38:19.866Z,1666035499.866 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193817.00,A,3648.16045,N,12147.28780,W,0.739,206.02,171022,,,A*7E
2022-10-17T19:38:19.868Z,1666035499.868 [NAL9602](INFO): GPS fix at 20221017T193817: (36.802674, -121.788130)
2022-10-17T19:38:19.918Z,1666035499.918 [Default:CheckIn:Read_GPS] Stopped
2022-10-17T19:38:19.918Z,1666035499.918 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-17T19:38:27.143Z,1666035507.143 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221017T174941/Courier0034.lzma
2022-10-17T19:38:28.145Z,1666035508.145 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Courier0034.lzma.bak
2022-10-17T19:38:28.145Z,1666035508.145 [DataOverHttps](INFO): SBD MOMSN=17247085
2022-10-17T19:38:44.935Z,1666035524.935 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221017T174941/Express0035.lzma
2022-10-17T19:38:45.937Z,1666035525.937 [DataOverHttps](INFO): Moved sent file to Logs/20221017T174941/Express0035.lzma.bak
2022-10-17T19:38:45.937Z,1666035525.937 [DataOverHttps](INFO): SBD MOMSN=17247092
2022-10-17T19:38:47.369Z,1666035527.369 [Default:CheckIn:Read_Iridium] Stopped
2022-10-17T19:38:47.369Z,1666035527.369 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-17T19:38:47.369Z,1666035527.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-17T19:38:50.584Z,1666035530.584 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-10-17T19:38:50.659Z,1666035530.659 [NAL9602](ERROR): received: 
+CSQ:0

OK432, 0, 0, 0, 0

OK
2022-10-17T19:39:16.352Z,1666035556.352 [CommandExec](IMPORTANT): got command quit
2022-10-17T19:39:17.355Z,1666035557.355 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-10-17T19:39:17.355Z,1666035557.355 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:17.356Z,1666035557.356 [CommandExec](INFO): Uninitializing the command executive.
2022-10-17T19:39:17.356Z,1666035557.356 [CommandExec](INFO): Uninitializing the command scheduler.
2022-10-17T19:39:17.356Z,1666035557.356 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.463Z,1666035557.463 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-10-17T19:39:17.463Z,1666035557.463 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-10-17T19:39:17.464Z,1666035557.464 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.464Z,1666035557.464 [NavChartDb](INFO): Join timeout helper Thread ID is 5722
2022-10-17T19:39:17.563Z,1666035557.563 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:17.564Z,1666035557.564 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.583Z,1666035557.583 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2022-10-17T19:39:17.583Z,1666035557.583 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.584Z,1666035557.584 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 5723
2022-10-17T19:39:17.824Z,1666035557.824 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:17.825Z,1666035557.825 [WetLabsUBAT](INFO): Powering down
2022-10-17T19:39:17.826Z,1666035557.826 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.831Z,1666035557.831 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-10-17T19:39:17.831Z,1666035557.831 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:17.832Z,1666035557.832 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5724
2022-10-17T19:39:18.151Z,1666035558.151 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:18.152Z,1666035558.152 [WetLabsBB2FL](INFO): Powering down
2022-10-17T19:39:18.152Z,1666035558.152 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.155Z,1666035558.155 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-10-17T19:39:18.155Z,1666035558.155 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.156Z,1666035558.156 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5725
2022-10-17T19:39:18.467Z,1666035558.467 [CTD_Seabird](INFO): Powering down
2022-10-17T19:39:18.479Z,1666035558.479 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:18.479Z,1666035558.479 [CTD_Seabird](INFO): Powering down
2022-10-17T19:39:18.491Z,1666035558.491 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.507Z,1666035558.507 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-10-17T19:39:18.507Z,1666035558.507 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.508Z,1666035558.508 [DAT](INFO): Join timeout helper Thread ID is 5726
2022-10-17T19:39:18.639Z,1666035558.639 [DAT](INFO): Powering down
2022-10-17T19:39:18.712Z,1666035558.712 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:18.712Z,1666035558.712 [DAT](INFO): Powering down
2022-10-17T19:39:18.713Z,1666035558.713 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.728Z,1666035558.728 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-10-17T19:39:18.728Z,1666035558.728 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:18.728Z,1666035558.728 [Radio_Surface](INFO): Join timeout helper Thread ID is 5727
2022-10-17T19:39:19.091Z,1666035559.091 [Radio_Surface](INFO): Powering down
2022-10-17T19:39:19.092Z,1666035559.092 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:19.092Z,1666035559.092 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:19.108Z,1666035559.108 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-10-17T19:39:19.108Z,1666035559.108 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:19.108Z,1666035559.108 [Onboard](INFO): Join timeout helper Thread ID is 5728
2022-10-17T19:39:19.749Z,1666035559.749 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-10-17T19:39:21.303Z,1666035561.303 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:21.304Z,1666035561.304 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.320Z,1666035561.320 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-10-17T19:39:21.320Z,1666035561.320 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.320Z,1666035561.320 [DataOverHttps](INFO): Join timeout helper Thread ID is 5729
2022-10-17T19:39:21.755Z,1666035561.755 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:21.756Z,1666035561.756 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.773Z,1666035561.773 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-10-17T19:39:21.773Z,1666035561.773 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.774Z,1666035561.774 [BackseatComponent](INFO): Join timeout helper Thread ID is 5730
2022-10-17T19:39:21.895Z,1666035561.895 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:21.895Z,1666035561.895 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.900Z,1666035561.900 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-10-17T19:39:21.900Z,1666035561.900 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.900Z,1666035561.900 [logger](INFO): Join timeout helper Thread ID is 5731
2022-10-17T19:39:21.939Z,1666035561.939 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:21.940Z,1666035561.940 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.960Z,1666035561.960 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-10-17T19:39:21.960Z,1666035561.960 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:21.960Z,1666035561.960 [CommandLine](INFO): Join timeout helper Thread ID is 5732
2022-10-17T19:39:22.015Z,1666035562.015 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:22.015Z,1666035562.015 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.020Z,1666035562.020 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-10-17T19:39:22.020Z,1666035562.020 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.020Z,1666035562.020 [CommandExec](INFO): Join timeout helper Thread ID is 5733
2022-10-17T19:39:22.021Z,1666035562.021 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-10-17T19:39:22.022Z,1666035562.022 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.022Z,1666035562.022 [controlThread](INFO): Join timeout helper Thread ID is 5734
2022-10-17T19:39:22.079Z,1666035562.079 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-17T19:39:22.079Z,1666035562.079 [controlThread](DEBUG): Uninitializing ControlThread
2022-10-17T19:39:22.080Z,1666035562.080 [AHRS_M2](INFO): Powering down
2022-10-17T19:39:22.152Z,1666035562.152 [NAL9602](INFO): Powering down
2022-10-17T19:39:22.223Z,1666035562.223 [RDI_Pathfinder](INFO): Powering down
2022-10-17T19:39:22.225Z,1666035562.225 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-10-17T19:39:22.226Z,1666035562.226 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-10-17T19:39:22.226Z,1666035562.226 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-10-17T19:39:22.226Z,1666035562.226 [MissionManager](INFO): Uninitializing Mission Default
2022-10-17T19:39:22.227Z,1666035562.227 [Default] Stopped
2022-10-17T19:39:22.227Z,1666035562.227 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-17T19:39:22.227Z,1666035562.227 [Default:B.GoToSurface] Stopped
2022-10-17T19:39:22.227Z,1666035562.227 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-17T19:39:22.227Z,1666035562.227 [Default:CheckIn] Stopped
2022-10-17T19:39:22.227Z,1666035562.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-17T19:39:22.227Z,1666035562.227 [Default:CheckIn:C.Wait] Stopped
2022-10-17T19:39:22.227Z,1666035562.227 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-17T19:39:22.230Z,1666035562.230 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-10-17T19:39:22.230Z,1666035562.230 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-10-17T19:39:22.230Z,1666035562.230 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-10-17T19:39:22.231Z,1666035562.231 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-10-17T19:39:22.231Z,1666035562.231 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-10-17T19:39:22.231Z,1666035562.231 [BuoyancyServo](INFO): Powering down
2022-10-17T19:39:22.243Z,1666035562.243 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-10-17T19:39:22.243Z,1666035562.243 [ElevatorServo](INFO): Powering down
2022-10-17T19:39:22.244Z,1666035562.244 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-10-17T19:39:22.244Z,1666035562.244 [MassServo](INFO): Powering down
2022-10-17T19:39:22.245Z,1666035562.245 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-10-17T19:39:22.245Z,1666035562.245 [RudderServo](INFO): Powering down
2022-10-17T19:39:22.246Z,1666035562.246 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2022-10-17T19:39:22.246Z,1666035562.246 [ThrusterServo](INFO): Powering down
2022-10-17T19:39:22.247Z,1666035562.247 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-10-17T19:39:22.247Z,1666035562.247 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-10-17T19:39:22.248Z,1666035562.248 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-10-17T19:39:22.248Z,1666035562.248 [CBIT](DEBUG): Powering off loads.
2022-10-17T19:39:22.259Z,1666035562.259 [CBIT](DEBUG): Disabling WDT.
2022-10-17T19:39:22.271Z,1666035562.271 [CBIT](DEBUG): Opening all GF detection circuits.
2022-10-17T19:39:22.272Z,1666035562.272 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.321Z,1666035562.321 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.329Z,1666035562.329 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.330Z,1666035562.330 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.336Z,1666035562.336 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.379Z,1666035562.379 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.443Z,1666035562.443 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.457Z,1666035562.457 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.460Z,1666035562.460 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.468Z,1666035562.468 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-17T19:39:22.525Z,1666035562.525 [logger ThreadHandler](INFO): Thread cancelled.