2023-06-05T20:45:50.624Z,1685997950.624 [Supervisor](DEBUG): Initializing supervisor.
2023-06-05T20:45:50.629Z,1685997950.629 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-05T20:45:50.629Z,1685997950.629 [SyncHandler](INFO): Protected caller Thread ID is 836
2023-06-05T20:45:50.630Z,1685997950.630 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-05T20:45:50.631Z,1685997950.631 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-05T20:45:50.631Z,1685997950.631 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2023-06-05T20:45:50.635Z,1685997950.635 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-05T20:45:50.653Z,1685997950.653 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-05T20:45:50.654Z,1685997950.654 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-05T20:45:50.654Z,1685997950.654 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2023-06-05T20:45:50.659Z,1685997950.659 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-05T20:45:50.660Z,1685997950.660 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-05T20:45:50.660Z,1685997950.660 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2023-06-05T20:45:50.662Z,1685997950.662 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-05T20:45:50.663Z,1685997950.663 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-05T20:45:50.663Z,1685997950.663 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2023-06-05T20:45:50.667Z,1685997950.667 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-05T20:45:50.667Z,1685997950.667 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-05T20:45:50.672Z,1685997950.672 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-05T20:45:50.931Z,1685997950.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-05T20:45:50.932Z,1685997950.932 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-05T20:45:51.012Z,1685997951.012 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-05T20:45:51.466Z,1685997951.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-05T20:45:51.468Z,1685997951.468 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-05T20:45:51.777Z,1685997951.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-05T20:45:51.778Z,1685997951.778 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-05T20:45:51.873Z,1685997951.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-05T20:45:51.875Z,1685997951.875 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-05T20:45:52.266Z,1685997952.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-05T20:45:52.268Z,1685997952.268 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-05T20:45:52.469Z,1685997952.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-05T20:45:52.469Z,1685997952.469 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-05T20:45:52.962Z,1685997952.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-05T20:45:52.964Z,1685997952.964 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-05T20:45:53.097Z,1685997953.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-05T20:45:53.099Z,1685997953.099 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-05T20:45:53.178Z,1685997953.178 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-05T20:45:53.891Z,1685997953.891 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-05T20:45:53.892Z,1685997953.892 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-05T20:45:54.979Z,1685997954.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-05T20:45:54.981Z,1685997954.981 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-05T20:45:55.166Z,1685997955.166 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-05T20:45:55.167Z,1685997955.167 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-05T20:45:55.276Z,1685997955.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-05T20:45:55.278Z,1685997955.278 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-05T20:45:55.495Z,1685997955.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-05T20:45:55.495Z,1685997955.495 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-05T20:45:55.725Z,1685997955.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-05T20:45:55.727Z,1685997955.727 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-06-05T20:45:55.731Z,1685997955.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-06-05T20:45:55.821Z,1685997955.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-06-05T20:45:55.906Z,1685997955.906 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-06-05T20:45:56.005Z,1685997956.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-06-05T20:45:56.090Z,1685997956.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-06-05T20:45:56.187Z,1685997956.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-06-05T20:45:56.286Z,1685997956.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-06-05T20:45:56.459Z,1685997956.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-06-05T20:45:56.536Z,1685997956.536 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-06-05T20:45:56.687Z,1685997956.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-06-05T20:45:56.823Z,1685997956.823 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-06-05T20:45:56.932Z,1685997956.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-06-05T20:45:57.195Z,1685997957.195 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-05T20:45:57.196Z,1685997957.196 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-05T20:45:57.211Z,1685997957.211 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-05T20:45:57.279Z,1685997957.279 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-05T20:45:57.339Z,1685997957.339 [VerticalControl] Loaded
2023-06-05T20:45:57.339Z,1685997957.339 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-05T20:45:57.342Z,1685997957.342 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-05T20:45:57.385Z,1685997957.385 [HorizontalControl] Loaded
2023-06-05T20:45:57.385Z,1685997957.385 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-05T20:45:57.387Z,1685997957.387 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-05T20:45:57.390Z,1685997957.390 [SpeedControl] Loaded
2023-06-05T20:45:57.391Z,1685997957.391 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-05T20:45:57.393Z,1685997957.393 [LoopControl](DEBUG): Construct LoopControl.
2023-06-05T20:45:57.394Z,1685997957.394 [LoopControl] Loaded
2023-06-05T20:45:57.394Z,1685997957.394 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-05T20:45:57.394Z,1685997957.394 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-05T20:45:57.396Z,1685997957.396 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-05T20:45:57.412Z,1685997957.412 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-05T20:45:57.412Z,1685997957.412 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-05T20:45:57.594Z,1685997957.594 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-05T20:45:57.595Z,1685997957.595 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-05T20:45:57.780Z,1685997957.780 [BuoyancyServo] Loaded
2023-06-05T20:45:57.780Z,1685997957.780 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-05T20:45:57.800Z,1685997957.800 [ElevatorServo] Loaded
2023-06-05T20:45:57.800Z,1685997957.800 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-05T20:45:57.819Z,1685997957.819 [MassServo] Loaded
2023-06-05T20:45:57.820Z,1685997957.820 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-05T20:45:57.838Z,1685997957.838 [RudderServo] Loaded
2023-06-05T20:45:57.838Z,1685997957.838 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-05T20:45:57.855Z,1685997957.855 [ThrusterServo] Loaded
2023-06-05T20:45:57.856Z,1685997957.856 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-06-05T20:45:57.856Z,1685997957.856 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-05T20:45:57.857Z,1685997957.857 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-05T20:45:57.994Z,1685997957.994 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-05T20:45:57.994Z,1685997957.994 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-05T20:45:58.008Z,1685997958.008 [NavChart] Loaded
2023-06-05T20:45:58.009Z,1685997958.009 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-05T20:45:58.014Z,1685997958.014 [UniversalFixResidualReporter] Loaded
2023-06-05T20:45:58.014Z,1685997958.014 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-05T20:45:58.015Z,1685997958.015 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-05T20:45:58.016Z,1685997958.016 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-05T20:45:58.096Z,1685997958.096 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-05T20:45:58.097Z,1685997958.097 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-05T20:45:58.848Z,1685997958.848 [AHRS_M2] Loaded
2023-06-05T20:45:58.848Z,1685997958.848 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-05T20:46:00.142Z,1685997960.142 [BPC1] Loaded
2023-06-05T20:46:00.143Z,1685997960.143 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-05T20:46:00.288Z,1685997960.288 [DataOverHttps] Loaded
2023-06-05T20:46:00.288Z,1685997960.288 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-05T20:46:00.289Z,1685997960.289 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409004E0
2023-06-05T20:46:00.290Z,1685997960.290 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925
2023-06-05T20:46:00.311Z,1685997960.311 [Depth_Keller] Loaded
2023-06-05T20:46:00.311Z,1685997960.311 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-05T20:46:00.316Z,1685997960.316 [DropWeight] Loaded
2023-06-05T20:46:00.316Z,1685997960.316 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-05T20:46:00.378Z,1685997960.378 [NAL9602] Loaded
2023-06-05T20:46:00.378Z,1685997960.378 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-05T20:46:00.408Z,1685997960.408 [Onboard] Loaded
2023-06-05T20:46:00.408Z,1685997960.408 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-05T20:46:00.409Z,1685997960.409 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409304E0
2023-06-05T20:46:00.409Z,1685997960.409 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926
2023-06-05T20:46:00.422Z,1685997960.422 [Power24vConverter] Loaded
2023-06-05T20:46:00.423Z,1685997960.423 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-05T20:46:00.436Z,1685997960.436 [Radio_Surface] Loaded
2023-06-05T20:46:00.436Z,1685997960.436 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-05T20:46:00.437Z,1685997960.437 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409604E0
2023-06-05T20:46:00.438Z,1685997960.438 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927
2023-06-05T20:46:00.439Z,1685997960.439 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-05T20:46:00.441Z,1685997960.441 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-05T20:46:00.513Z,1685997960.513 [DepthRateCalculator] Loaded
2023-06-05T20:46:00.513Z,1685997960.513 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-05T20:46:00.518Z,1685997960.518 [PitchRateCalculator] Loaded
2023-06-05T20:46:00.518Z,1685997960.518 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-05T20:46:00.527Z,1685997960.527 [SpeedCalculator] Loaded
2023-06-05T20:46:00.527Z,1685997960.527 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-05T20:46:00.532Z,1685997960.532 [YawRateCalculator] Loaded
2023-06-05T20:46:00.532Z,1685997960.532 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-05T20:46:00.551Z,1685997960.551 [ElevatorOffsetCalculator] Loaded
2023-06-05T20:46:00.551Z,1685997960.551 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-05T20:46:00.552Z,1685997960.552 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-05T20:46:00.553Z,1685997960.553 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-05T20:46:00.727Z,1685997960.727 [CANONSampler] Loaded
2023-06-05T20:46:00.727Z,1685997960.727 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-06-05T20:46:00.787Z,1685997960.787 [CTD_Seabird] Loaded
2023-06-05T20:46:00.787Z,1685997960.787 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-05T20:46:00.788Z,1685997960.788 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A194E0
2023-06-05T20:46:00.789Z,1685997960.789 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 928
2023-06-05T20:46:00.809Z,1685997960.809 [PAR_Licor] Loaded
2023-06-05T20:46:00.810Z,1685997960.810 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-05T20:46:00.841Z,1685997960.841 [WetLabsBB2FL] Loaded
2023-06-05T20:46:00.841Z,1685997960.841 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-05T20:46:00.842Z,1685997960.842 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A494E0
2023-06-05T20:46:00.842Z,1685997960.842 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 929
2023-06-05T20:46:00.843Z,1685997960.843 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-05T20:46:00.844Z,1685997960.844 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-05T20:46:00.886Z,1685997960.886 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-05T20:46:00.887Z,1685997960.887 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-05T20:46:01.244Z,1685997961.244 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-05T20:46:01.245Z,1685997961.245 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-05T20:46:01.412Z,1685997961.412 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-05T20:46:01.421Z,1685997961.421 [SBIT] Loaded
2023-06-05T20:46:01.422Z,1685997961.422 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-05T20:46:01.425Z,1685997961.425 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-05T20:46:01.438Z,1685997961.438 [IBIT] Loaded
2023-06-05T20:46:01.438Z,1685997961.438 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-05T20:46:01.444Z,1685997961.444 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-05T20:46:01.550Z,1685997961.550 [CBIT] Loaded
2023-06-05T20:46:01.550Z,1685997961.550 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-05T20:46:01.551Z,1685997961.551 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-05T20:46:01.553Z,1685997961.553 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-05T20:46:01.675Z,1685997961.675 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-05T20:46:01.681Z,1685997961.681 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-05T20:46:01.684Z,1685997961.684 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-05T20:46:01.695Z,1685997961.695 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-05T20:46:01.696Z,1685997961.696 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B814E0
2023-06-05T20:46:01.697Z,1685997961.697 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930
2023-06-05T20:46:01.701Z,1685997961.701 [Supervisor](INFO): Main Thread ID is 829
2023-06-05T20:46:01.701Z,1685997961.701 [Supervisor](DEBUG): Running supervisor.
2023-06-05T20:46:01.702Z,1685997961.702 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931
2023-06-05T20:46:01.702Z,1685997961.702 [CommandExec](INFO): Initializing the command executive.
2023-06-05T20:46:01.704Z,1685997961.704 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932
2023-06-05T20:46:01.706Z,1685997961.706 [controlThread ThreadHandler](INFO): Handler Thread ID is 933
2023-06-05T20:46:01.707Z,1685997961.707 [controlThread](DEBUG): Initializing ControlThread
2023-06-05T20:46:01.707Z,1685997961.707 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-05T20:46:01.709Z,1685997961.709 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-05T20:46:01.710Z,1685997961.710 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-05T20:46:01.710Z,1685997961.710 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-05T20:46:01.712Z,1685997961.712 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-05T20:46:01.713Z,1685997961.713 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-05T20:46:01.718Z,1685997961.718 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-05T20:46:01.718Z,1685997961.718 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-05T20:46:01.718Z,1685997961.718 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-05T20:46:01.718Z,1685997961.718 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-05T20:46:01.719Z,1685997961.719 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-05T20:46:01.724Z,1685997961.724 [SBIT](INFO): Initialize SBIT Component.
2023-06-05T20:46:01.725Z,1685997961.725 [SBIT](IMPORTANT): git: 2023-03-30-8-g9f4e94ede
2023-06-05T20:46:01.725Z,1685997961.725 [SBIT](INFO): git hash: 9f4e94ede96dd26b46ac6117d56fbd84feccae72
2023-06-05T20:46:01.725Z,1685997961.725 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-05T20:46:01.726Z,1685997961.726 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-06-05T20:46:01.727Z,1685997961.727 [SBIT](INFO): Beginning SBIT in 75.000000 seconds.
2023-06-05T20:46:01.728Z,1685997961.728 [logger ThreadHandler](INFO): Handler Thread ID is 934
2023-06-05T20:46:01.744Z,1685997961.744 [IBIT](INFO): Initialize IBIT Component.
2023-06-05T20:46:01.745Z,1685997961.745 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-05T20:46:01.752Z,1685997961.752 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935
2023-06-05T20:46:01.753Z,1685997961.753 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-05T20:46:01.756Z,1685997961.756 [CBIT](DEBUG): Initialized mux pins.
2023-06-05T20:46:01.756Z,1685997961.756 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-05T20:46:01.764Z,1685997961.764 [Onboard ThreadHandler](INFO): Handler Thread ID is 936
2023-06-05T20:46:01.780Z,1685997961.780 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-05T20:46:01.780Z,1685997961.780 [CBIT](DEBUG): Initializing heartbeat.
2023-06-05T20:46:01.783Z,1685997961.783 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937
2023-06-05T20:46:01.800Z,1685997961.800 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 938
2023-06-05T20:46:01.801Z,1685997961.801 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-05T20:46:01.806Z,1685997961.806 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 940
2023-06-05T20:46:01.808Z,1685997961.808 [WetLabsBB2FL](INFO): Powering up
2023-06-05T20:46:01.809Z,1685997961.809 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942
2023-06-05T20:46:01.817Z,1685997961.817 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-06-05T20:46:01.818Z,1685997961.818 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-06-05T20:46:01.818Z,1685997961.818 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-06-05T20:46:01.818Z,1685997961.818 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-06-05T20:46:01.818Z,1685997961.818 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-06-05T20:46:01.818Z,1685997961.818 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-06-05T20:46:01.819Z,1685997961.819 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-06-05T20:46:01.819Z,1685997961.819 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-06-05T20:46:01.852Z,1685997961.852 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-05T20:46:01.852Z,1685997961.852 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-05T20:46:01.892Z,1685997961.892 [CBIT](DEBUG): Backplane powered.
2023-06-05T20:46:01.893Z,1685997961.893 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-05T20:46:01.920Z,1685997961.920 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-05T20:46:01.943Z,1685997961.943 [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>


2023-06-05T20:46:01.944Z,1685997961.944 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-05T20:46:02.026Z,1685997962.026 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-05T20:46:02.027Z,1685997962.027 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-05T20:46:02.030Z,1685997962.030 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-05T20:46:02.075Z,1685997962.075 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-05T20:46:02.078Z,1685997962.078 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-05T20:46:02.112Z,1685997962.112 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-05T20:46:02.115Z,1685997962.115 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-06-05T20:46:02.128Z,1685997962.128 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2023-06-05T20:46:02.140Z,1685997962.140 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-05T20:46:02.188Z,1685997962.188 [Radio_Surface](INFO): Powering up
2023-06-05T20:46:02.282Z,1685997962.282 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1831.023193 decibar, 0.000000 m
2023-06-05T20:46:02.283Z,1685997962.283 [Power24vConverter](INFO): Powering up.
2023-06-05T20:46:02.283Z,1685997962.283 [CANONSampler](INFO): Powering down
2023-06-05T20:46:02.298Z,1685997962.298 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-06-05T20:46:02.326Z,1685997962.326 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-05T20:46:02.336Z,1685997962.336 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-05T20:46:02.337Z,1685997962.337 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-05T20:46:02.344Z,1685997962.344 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-05T20:46:02.345Z,1685997962.345 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-05T20:46:02.352Z,1685997962.352 [MassServo](DEBUG): Initializing MassServo.
2023-06-05T20:46:02.353Z,1685997962.353 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-05T20:46:02.360Z,1685997962.360 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-05T20:46:02.361Z,1685997962.361 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-06-05T20:46:02.368Z,1685997962.368 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-06-05T20:46:04.420Z,1685997964.420 [WetLabsBB2FL](INFO): Powering down
2023-06-05T20:46:30.418Z,1685997990.418 [NAL9602](INFO): Powering up NAL9602
2023-06-05T20:46:41.329Z,1685998001.329 [NAL9602](INFO): NAL9602 initialized
2023-06-05T20:47:17.331Z,1685998037.331 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-05T20:47:17.335Z,1685998037.335 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-05T20:47:28.221Z,1685998048.221 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-06-05T20:47:28.633Z,1685998048.633 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-05T20:47:35.076Z,1685998055.076 [CommandExec](IMPORTANT): got command failComponent
2023-06-05T20:47:35.077Z,1685998055.077 [CommandExec](IMPORTANT): Failed components:
2023-06-05T20:47:35.077Z,1685998055.077 [CommandExec](IMPORTANT): No failed Components.
2023-06-05T20:47:39.613Z,1685998059.613 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-06-05T20:47:40.025Z,1685998060.025 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-05T20:47:50.900Z,1685998070.900 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-06-05T20:47:50.901Z,1685998070.901 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2023-06-05T20:48:04.537Z,1685998084.537 [CommandExec](IMPORTANT): got command gfscan
2023-06-05T20:48:04.646Z,1685998084.646 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-05T20:48:11.099Z,1685998091.099 [SBIT](IMPORTANT): SBIT PASSED
2023-06-05T20:48:11.099Z,1685998091.099 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-05T20:48:11.100Z,1685998091.100 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-06-05T20:48:11.100Z,1685998091.100 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=14 count;

2023-06-05T20:48:11.100Z,1685998091.100 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-06-05T20:48:11.100Z,1685998091.100 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-06-05T20:48:11.101Z,1685998091.101 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-06-05T20:48:11.101Z,1685998091.101 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-06-05T20:48:11.101Z,1685998091.101 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=311.015496 cubic_centimeter;

2023-06-05T20:48:11.101Z,1685998091.101 [SBIT](IMPORTANT): VerticalControl.massDefault=-13.756980 millimeter;

2023-06-05T20:48:11.101Z,1685998091.101 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;

2023-06-05T20:48:11.443Z,1685998091.443 [MissionManager](IMPORTANT): Started mission Startup
2023-06-05T20:48:11.443Z,1685998091.443 [Startup] Running Loop=1
2023-06-05T20:48:11.443Z,1685998091.443 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-05T20:48:11.443Z,1685998091.443 [Startup:A.GoToSurface] Running Loop=1
2023-06-05T20:48:11.444Z,1685998091.444 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-05T20:48:11.444Z,1685998091.444 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-05T20:48:11.445Z,1685998091.445 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-05T20:48:11.445Z,1685998091.445 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-05T20:48:11.445Z,1685998091.445 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-05T20:48:11.446Z,1685998091.446 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-05T20:48:11.447Z,1685998091.447 [Startup:StartupSatComms] Running Loop=1
2023-06-05T20:48:11.447Z,1685998091.447 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-05T20:48:11.447Z,1685998091.447 [Startup:StartupSatComms:A] Running Loop=1
2023-06-05T20:48:11.931Z,1685998091.931 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-05T20:48:15.526Z,1685998095.526 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.001469
CHAN A1 (24V): 0.000030
CHAN A2 (12V): -0.001823
CHAN A3 (5V): -0.001469
CHAN B0 (3.3V): -0.000059
CHAN B1 (3.15aV): -0.000285
CHAN B2 (3.15bV): -0.000544
CHAN B3 (GND): -0.000063
OPEN: -0.000457
Full Scale: +/- 1 mA
2023-06-05T20:49:01.962Z,1685998141.962 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-06-05T20:49:01.962Z,1685998141.962 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T20:49:01.973Z,1685998141.973 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T20:49:02.346Z,1685998142.346 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T20:49:02.346Z,1685998142.346 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-06-05T20:49:11.634Z,1685998151.634 [Startup:StartupSatComms:A](INFO): Timed out from 2023-06-05T20:48:11.4Z
2023-06-05T20:49:11.634Z,1685998151.634 [Startup:StartupSatComms:A] Stopped
2023-06-05T20:49:11.634Z,1685998151.634 [Startup:StartupSatComms:B] Running Loop=1
2023-06-05T20:49:12.046Z,1685998152.046 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-05T20:49:45.414Z,1685998185.414 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004500
2023-06-05T20:49:53.007Z,1685998193.007 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230605T203357/Courier0007.lzma
2023-06-05T20:49:54.010Z,1685998194.010 [DataOverHttps](INFO): Moved sent file to Logs/20230605T203357/Courier0007.lzma.bak
2023-06-05T20:49:54.010Z,1685998194.010 [DataOverHttps](INFO): SBD MOMSN=18397454
2023-06-05T20:50:09.539Z,1685998209.539 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230605T204550/Courier0000.lzma
2023-06-05T20:50:10.542Z,1685998210.542 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0000.lzma.bak
2023-06-05T20:50:10.542Z,1685998210.542 [DataOverHttps](INFO): SBD MOMSN=18397456
2023-06-05T20:50:11.864Z,1685998211.864 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-05T20:49:11.6Z
2023-06-05T20:50:11.864Z,1685998211.864 [Startup:StartupSatComms:B] Stopped
2023-06-05T20:50:11.864Z,1685998211.864 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-05T20:50:11.864Z,1685998211.864 [Startup:StartupSatComms] Stopped
2023-06-05T20:50:11.864Z,1685998211.864 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-05T20:50:11.865Z,1685998211.865 [Startup](INFO): Completed Startup
2023-06-05T20:50:11.865Z,1685998211.865 [MissionManager](INFO): Startup is completed.
2023-06-05T20:50:11.865Z,1685998211.865 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-05T20:50:11.865Z,1685998211.865 [Startup] Stopped
2023-06-05T20:50:11.866Z,1685998211.866 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-05T20:50:11.866Z,1685998211.866 [Startup:A.GoToSurface] Stopped
2023-06-05T20:50:11.866Z,1685998211.866 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-05T20:50:12.277Z,1685998212.277 [MissionManager](IMPORTANT): Started mission Default
2023-06-05T20:50:12.277Z,1685998212.277 [Default] Running Loop=1
2023-06-05T20:50:12.277Z,1685998212.277 [Default](DEBUG): Aggregate::initialize Default
2023-06-05T20:50:12.277Z,1685998212.277 [Default:B.GoToSurface] Running Loop=1
2023-06-05T20:50:12.277Z,1685998212.277 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-05T20:50:12.278Z,1685998212.278 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-05T20:50:12.278Z,1685998212.278 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-05T20:50:12.278Z,1685998212.278 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-05T20:50:12.278Z,1685998212.278 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-05T20:50:12.279Z,1685998212.279 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-05T20:50:12.279Z,1685998212.279 [Default:A.Wait] Running Loop=1
2023-06-05T20:50:12.279Z,1685998212.279 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-05T20:50:25.603Z,1685998225.603 [Default:A.Wait](INFO): Done Waiting.
2023-06-05T20:50:25.603Z,1685998225.603 [Default:A.Wait] Stopped
2023-06-05T20:50:25.604Z,1685998225.604 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T20:50:26.019Z,1685998226.019 [Default:CheckIn] Running Loop=1
2023-06-05T20:50:26.019Z,1685998226.019 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T20:50:26.019Z,1685998226.019 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T20:50:26.406Z,1685998226.406 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-05T20:50:48.763Z,1685998248.763 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230605T203357/Express0008.lzma
2023-06-05T20:50:49.765Z,1685998249.765 [DataOverHttps](INFO): Moved sent file to Logs/20230605T203357/Express0008.lzma.bak
2023-06-05T20:50:49.766Z,1685998249.766 [DataOverHttps](INFO): SBD MOMSN=18397460
2023-06-05T20:51:45.191Z,1685998305.191 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T20:52:02.964Z,1685998322.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-06-05T20:52:02.964Z,1685998322.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T20:52:02.974Z,1685998322.974 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T20:52:03.383Z,1685998323.383 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T20:52:03.383Z,1685998323.383 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-06-05T20:52:57.892Z,1685998377.892 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:53:12.840Z,1685998392.840 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:53:28.206Z,1685998408.206 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:53:43.146Z,1685998423.146 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:53:58.498Z,1685998438.498 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:54:13.848Z,1685998453.848 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:54:22.347Z,1685998462.347 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205402.00,A,3648.16998,N,12147.27972,W,0.136,0.00,050623,,,A*75
2023-06-05T20:54:22.350Z,1685998462.350 [NAL9602](INFO): GPS fix at 20230605T205402: (36.802833, -121.787995)
2023-06-05T20:54:22.361Z,1685998462.361 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T20:54:22.361Z,1685998462.361 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T20:54:22.766Z,1685998462.766 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-05T20:54:29.619Z,1685998469.619 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:54:31.712Z,1685998471.712 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230605T204550/Courier0004.lzma
2023-06-05T20:54:32.713Z,1685998472.713 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0004.lzma.bak
2023-06-05T20:54:32.714Z,1685998472.714 [DataOverHttps](INFO): SBD MOMSN=18397471
2023-06-05T20:54:44.728Z,1685998484.728 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:54:54.413Z,1685998494.413 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T20:54:54.485Z,1685998494.485 [DataOverHttps](INFO): Sending 963 bytes from file Logs/20230605T204550/Express0001.lzma
2023-06-05T20:54:55.438Z,1685998495.438 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0001.lzma.bak
2023-06-05T20:54:55.438Z,1685998495.438 [DataOverHttps](INFO): SBD MOMSN=18397474
2023-06-05T20:55:00.063Z,1685998500.063 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T20:55:14.009Z,1685998514.009 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20230605T204550/Express0005.lzma
2023-06-05T20:55:15.010Z,1685998515.010 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0005.lzma.bak
2023-06-05T20:55:15.010Z,1685998515.010 [DataOverHttps](INFO): SBD MOMSN=18397502
2023-06-05T20:55:16.703Z,1685998516.703 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T20:55:16.703Z,1685998516.703 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T20:55:16.708Z,1685998516.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T20:56:03.153Z,1685998563.153 [Power24vConverter](INFO): Powering down.
2023-06-05T21:00:17.327Z,1685998817.327 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:00:17.327Z,1685998817.327 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:00:17.327Z,1685998817.327 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:00:17.327Z,1685998817.327 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:00:17.692Z,1685998817.692 [Default:CheckIn:D] Stopped
2023-06-05T21:00:17.692Z,1685998817.692 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:00:18.105Z,1685998818.105 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.090249 min 
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn:E] Stopped
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn] Stopped
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn](INFO): Running loop #2
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn] Running Loop=2
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:00:18.106Z,1685998818.106 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:00:20.094Z,1685998820.094 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210001.00,A,3648.17002,N,12147.28119,W,0.097,269.43,050623,,,A*77
2023-06-05T21:00:20.097Z,1685998820.097 [NAL9602](INFO): GPS fix at 20230605T210001: (36.802834, -121.788020)
2023-06-05T21:00:20.107Z,1685998820.107 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:00:20.107Z,1685998820.107 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:00:28.147Z,1685998828.147 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0007.lzma
2023-06-05T21:00:29.150Z,1685998829.150 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0007.lzma.bak
2023-06-05T21:00:29.150Z,1685998829.150 [DataOverHttps](INFO): SBD MOMSN=18397514
2023-06-05T21:00:48.143Z,1685998848.143 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20230605T204550/Express0008.lzma
2023-06-05T21:00:49.145Z,1685998849.145 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0008.lzma.bak
2023-06-05T21:00:49.146Z,1685998849.146 [DataOverHttps](INFO): SBD MOMSN=18397517
2023-06-05T21:00:50.462Z,1685998850.462 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:00:50.462Z,1685998850.462 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:00:50.462Z,1685998850.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:00:50.832Z,1685998850.832 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T21:00:50.916Z,1685998850.916 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-05T21:02:17.700Z,1685998937.700 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:02:32.658Z,1685998952.658 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:02:47.990Z,1685998967.990 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:03:02.940Z,1685998982.940 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:03:18.290Z,1685998998.290 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:03:33.239Z,1685999013.239 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:03:48.186Z,1685999028.186 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:04:03.540Z,1685999043.540 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:04:18.891Z,1685999058.891 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:04:33.030Z,1685999073.030 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-05T21:05:22.725Z,1685999122.725 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T21:05:51.020Z,1685999151.020 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:05:51.020Z,1685999151.020 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:05:51.020Z,1685999151.020 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:05:51.020Z,1685999151.020 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:05:51.423Z,1685999151.423 [Default:CheckIn:D] Stopped
2023-06-05T21:05:51.423Z,1685999151.423 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.652427 min 
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn:E] Stopped
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn] Stopped
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn](INFO): Running loop #3
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn] Running Loop=3
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:05:51.829Z,1685999151.829 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:05:53.855Z,1685999153.855 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210534.00,A,3648.17016,N,12147.27917,W,0.097,269.43,050623,,,A*78
2023-06-05T21:05:53.857Z,1685999153.857 [NAL9602](INFO): GPS fix at 20230605T210534: (36.802836, -121.787986)
2023-06-05T21:05:53.868Z,1685999153.868 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:05:53.868Z,1685999153.868 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:06:01.511Z,1685999161.511 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0010.lzma
2023-06-05T21:06:02.513Z,1685999162.513 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0010.lzma.bak
2023-06-05T21:06:02.514Z,1685999162.514 [DataOverHttps](INFO): SBD MOMSN=18397522
2023-06-05T21:06:18.479Z,1685999178.479 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230605T204550/Express0011.lzma
2023-06-05T21:06:19.482Z,1685999179.482 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0011.lzma.bak
2023-06-05T21:06:19.482Z,1685999179.482 [DataOverHttps](INFO): SBD MOMSN=18397525
2023-06-05T21:06:20.920Z,1685999180.920 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:06:20.920Z,1685999180.920 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:06:20.920Z,1685999180.920 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:06:25.765Z,1685999185.765 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T21:11:21.498Z,1685999481.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:11:21.498Z,1685999481.498 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:11:21.498Z,1685999481.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:11:21.498Z,1685999481.498 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:11:21.907Z,1685999481.907 [Default:CheckIn:D] Stopped
2023-06-05T21:11:21.907Z,1685999481.907 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.160502 min 
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn:E] Stopped
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn] Stopped
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn](INFO): Running loop #4
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn] Running Loop=4
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:11:22.298Z,1685999482.298 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:11:24.315Z,1685999484.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211105.00,A,3648.16607,N,12147.28308,W,0.194,212.06,050623,,,A*7C
2023-06-05T21:11:24.317Z,1685999484.317 [NAL9602](INFO): GPS fix at 20230605T211105: (36.802768, -121.788051)
2023-06-05T21:11:24.327Z,1685999484.327 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:11:24.327Z,1685999484.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:11:32.011Z,1685999492.011 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0013.lzma
2023-06-05T21:11:33.014Z,1685999493.014 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0013.lzma.bak
2023-06-05T21:11:33.014Z,1685999493.014 [DataOverHttps](INFO): SBD MOMSN=18397537
2023-06-05T21:11:46.526Z,1685999506.526 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:11:48.943Z,1685999508.943 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230605T204550/Express0014.lzma
2023-06-05T21:11:49.945Z,1685999509.945 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0014.lzma.bak
2023-06-05T21:11:49.946Z,1685999509.946 [DataOverHttps](INFO): SBD MOMSN=18397540
2023-06-05T21:11:51.409Z,1685999511.409 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:11:51.409Z,1685999511.409 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:11:51.409Z,1685999511.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:12:01.880Z,1685999521.880 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:12:17.637Z,1685999537.637 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:12:32.986Z,1685999552.986 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:12:47.950Z,1685999567.950 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:13:03.302Z,1685999583.302 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:13:18.654Z,1685999598.654 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:13:33.602Z,1685999613.602 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:13:48.955Z,1685999628.955 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T21:16:26.987Z,1685999786.987 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T21:16:52.007Z,1685999812.007 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:16:52.007Z,1685999812.007 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:16:52.007Z,1685999812.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:16:52.007Z,1685999812.007 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:16:52.419Z,1685999812.419 [Default:CheckIn:D] Stopped
2023-06-05T21:16:52.419Z,1685999812.419 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.669031 min 
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn:E] Stopped
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn] Stopped
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn](INFO): Running loop #5
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn] Running Loop=5
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:16:52.833Z,1685999812.833 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:16:54.835Z,1685999814.835 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211635.00,A,3648.16670,N,12147.28133,W,0.214,198.34,050623,,,A*79
2023-06-05T21:16:54.837Z,1685999814.837 [NAL9602](INFO): GPS fix at 20230605T211635: (36.802778, -121.788022)
2023-06-05T21:16:54.847Z,1685999814.847 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:16:54.847Z,1685999814.847 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:17:02.467Z,1685999822.467 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0016.lzma
2023-06-05T21:17:02.498Z,1685999822.498 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 5.
2023-06-05T21:17:02.502Z,1685999822.502 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2023-06-05T21:17:03.469Z,1685999823.469 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0016.lzma.bak
2023-06-05T21:17:03.470Z,1685999823.470 [DataOverHttps](INFO): SBD MOMSN=18397545
2023-06-05T21:17:21.883Z,1685999841.883 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230605T204550/Express0017.lzma
2023-06-05T21:17:22.885Z,1685999842.885 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0017.lzma.bak
2023-06-05T21:17:22.886Z,1685999842.886 [DataOverHttps](INFO): SBD MOMSN=18397548
2023-06-05T21:17:24.389Z,1685999844.389 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:17:24.389Z,1685999844.389 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:17:24.390Z,1685999844.390 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:17:26.789Z,1685999846.789 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T21:22:24.949Z,1686000144.949 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:22:24.949Z,1686000144.949 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:22:24.949Z,1686000144.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:22:24.949Z,1686000144.949 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:22:25.359Z,1686000145.359 [Default:CheckIn:D] Stopped
2023-06-05T21:22:25.359Z,1686000145.359 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:22:25.763Z,1686000145.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.218028 min 
2023-06-05T21:22:25.763Z,1686000145.763 [Default:CheckIn:E] Stopped
2023-06-05T21:22:25.763Z,1686000145.763 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn] Stopped
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn](INFO): Running loop #6
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn] Running Loop=6
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:22:25.764Z,1686000145.764 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:22:27.775Z,1686000147.775 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212208.00,A,3648.16916,N,12147.27880,W,0.156,198.34,050623,,,A*74
2023-06-05T21:22:27.786Z,1686000147.786 [NAL9602](INFO): GPS fix at 20230605T212208: (36.802819, -121.787980)
2023-06-05T21:22:27.796Z,1686000147.796 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:22:27.796Z,1686000147.796 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:22:35.259Z,1686000155.259 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230605T204550/Courier0019.lzma
2023-06-05T21:22:36.270Z,1686000156.270 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0019.lzma.bak
2023-06-05T21:22:36.270Z,1686000156.270 [DataOverHttps](INFO): SBD MOMSN=18397563
2023-06-05T21:22:54.427Z,1686000174.427 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230605T204550/Express0020.lzma
2023-06-05T21:22:55.430Z,1686000175.430 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0020.lzma.bak
2023-06-05T21:22:55.430Z,1686000175.430 [DataOverHttps](INFO): SBD MOMSN=18397566
2023-06-05T21:22:56.921Z,1686000176.921 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:22:56.921Z,1686000176.921 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:22:56.922Z,1686000176.922 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:22:58.525Z,1686000178.525 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T21:22:58.608Z,1686000178.608 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-05T21:27:29.613Z,1686000449.613 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T21:27:57.499Z,1686000477.499 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:27:57.499Z,1686000477.499 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:27:57.499Z,1686000477.499 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:27:57.499Z,1686000477.499 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:27:57.915Z,1686000477.915 [Default:CheckIn:D] Stopped
2023-06-05T21:27:57.915Z,1686000477.915 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:27:58.310Z,1686000478.310 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.760624 min 
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn:E] Stopped
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn] Stopped
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn](INFO): Running loop #7
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn] Running Loop=7
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:27:58.311Z,1686000478.311 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:28:00.323Z,1686000480.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212741.00,A,3648.16341,N,12147.28003,W,0.194,198.34,050623,,,A*76
2023-06-05T21:28:00.325Z,1686000480.325 [NAL9602](INFO): GPS fix at 20230605T212741: (36.802723, -121.788000)
2023-06-05T21:28:00.335Z,1686000480.335 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:28:00.335Z,1686000480.335 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:28:07.287Z,1686000487.287 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0022.lzma
2023-06-05T21:28:08.290Z,1686000488.290 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0022.lzma.bak
2023-06-05T21:28:08.290Z,1686000488.290 [DataOverHttps](INFO): SBD MOMSN=18397570
2023-06-05T21:28:23.927Z,1686000503.927 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230605T204550/Express0023.lzma
2023-06-05T21:28:24.929Z,1686000504.929 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0023.lzma.bak
2023-06-05T21:28:24.930Z,1686000504.930 [DataOverHttps](INFO): SBD MOMSN=18397573
2023-06-05T21:28:26.603Z,1686000506.603 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:28:26.603Z,1686000506.603 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:28:26.603Z,1686000506.603 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:28:33.041Z,1686000513.041 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T21:33:27.177Z,1686000807.177 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T21:33:27.177Z,1686000807.177 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:33:27.177Z,1686000807.177 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:33:27.178Z,1686000807.178 [Default:CheckIn:D] Running Loop=1
2023-06-05T21:33:27.574Z,1686000807.574 [Default:CheckIn:D] Stopped
2023-06-05T21:33:27.574Z,1686000807.574 [Default:CheckIn:E] Running Loop=1
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.254944 min 
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn:E] Stopped
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn] Stopped
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:33:27.973Z,1686000807.973 [Default:CheckIn](INFO): Running loop #8
2023-06-05T21:33:27.974Z,1686000807.974 [Default:CheckIn] Running Loop=8
2023-06-05T21:33:27.974Z,1686000807.974 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T21:33:27.974Z,1686000807.974 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T21:33:29.991Z,1686000809.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213310.00,A,3648.16460,N,12147.28554,W,0.253,135.13,050623,,,A*7E
2023-06-05T21:33:29.993Z,1686000809.993 [NAL9602](INFO): GPS fix at 20230605T213310: (36.802743, -121.788092)
2023-06-05T21:33:30.004Z,1686000810.004 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T21:33:30.004Z,1686000810.004 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T21:33:36.727Z,1686000816.727 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0025.lzma
2023-06-05T21:33:37.730Z,1686000817.730 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0025.lzma.bak
2023-06-05T21:33:37.730Z,1686000817.730 [DataOverHttps](INFO): SBD MOMSN=18397584
2023-06-05T21:33:53.815Z,1686000833.815 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230605T204550/Express0026.lzma
2023-06-05T21:33:54.818Z,1686000834.818 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0026.lzma.bak
2023-06-05T21:33:54.818Z,1686000834.818 [DataOverHttps](INFO): SBD MOMSN=18397587
2023-06-05T21:33:56.280Z,1686000836.280 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T21:33:56.281Z,1686000836.281 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T21:33:56.281Z,1686000836.281 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:34:00.702Z,1686000840.702 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T21:34:00.784Z,1686000840.784 [NAL9602](ERROR): received: 
+CSQ:1

OK
2023-06-05T21:34:59.694Z,1686000899.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T21:34:59.695Z,1686000899.695 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T21:35:39.949Z,1686000939.949 [DataOverHttps](IMPORTANT): SBD MTMSN=20230605T213520
2023-06-05T21:35:47.324Z,1686000947.324 [DataOverHttps](INFO): Received command: load Maintenance/tank_ballast_and_trim.xml;set ballast_and_trim.EstimationConfidence 98 %;run
2023-06-05T21:35:47.354Z,1686000947.354 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/tank_ballast_and_trim.xml
2023-06-05T21:35:47.354Z,1686000947.354 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2023-06-05T21:35:47.491Z,1686000947.491 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2023-06-05T21:35:47.494Z,1686000947.494 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2023-06-05T21:35:47.496Z,1686000947.496 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2023-06-05T21:35:47.499Z,1686000947.499 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2023-06-05T21:35:47.502Z,1686000947.502 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2023-06-05T21:35:47.504Z,1686000947.504 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2023-06-05T21:35:47.507Z,1686000947.507 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2023-06-05T21:35:47.510Z,1686000947.510 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2023-06-05T21:35:47.513Z,1686000947.513 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2023-06-05T21:35:47.515Z,1686000947.515 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2023-06-05T21:35:47.518Z,1686000947.518 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2023-06-05T21:35:47.521Z,1686000947.521 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2023-06-05T21:35:47.524Z,1686000947.524 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2023-06-05T21:35:47.526Z,1686000947.526 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2023-06-05T21:35:47.527Z,1686000947.527 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2023-06-05T21:35:47.949Z,1686000947.949 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2023-06-05T21:35:47.968Z,1686000947.968 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2023-06-05T21:35:47.971Z,1686000947.971 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2023-06-05T21:35:47.974Z,1686000947.974 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2023-06-05T21:35:47.976Z,1686000947.976 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2023-06-05T21:35:47.979Z,1686000947.979 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2023-06-05T21:35:47.982Z,1686000947.982 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2023-06-05T21:35:47.985Z,1686000947.985 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2023-06-05T21:35:47.990Z,1686000947.990 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2023-06-05T21:35:47.993Z,1686000947.993 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2023-06-05T21:35:47.995Z,1686000947.995 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2023-06-05T21:35:47.998Z,1686000947.998 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2023-06-05T21:35:48.001Z,1686000948.001 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2023-06-05T21:35:48.003Z,1686000948.003 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2023-06-05T21:35:48.027Z,1686000948.027 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2023-06-05T21:35:48.030Z,1686000948.030 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2023-06-05T21:35:48.034Z,1686000948.034 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2023-06-05T21:35:48.037Z,1686000948.037 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2023-06-05T21:35:48.053Z,1686000948.053 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2023-06-05T21:35:48.057Z,1686000948.057 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2023-06-05T21:35:48.060Z,1686000948.060 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2023-06-05T21:35:48.063Z,1686000948.063 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2023-06-05T21:35:48.085Z,1686000948.085 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2023-06-05T21:35:48.088Z,1686000948.088 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2023-06-05T21:35:48.091Z,1686000948.091 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2023-06-05T21:35:48.104Z,1686000948.104 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2023-06-05T21:35:48.107Z,1686000948.107 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2023-06-05T21:35:48.110Z,1686000948.110 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2023-06-05T21:35:48.129Z,1686000948.129 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2023-06-05T21:35:48.132Z,1686000948.132 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2023-06-05T21:35:48.135Z,1686000948.135 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2023-06-05T21:35:48.138Z,1686000948.138 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2023-06-05T21:35:48.156Z,1686000948.156 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2023-06-05T21:35:48.159Z,1686000948.159 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2023-06-05T21:35:48.162Z,1686000948.162 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2023-06-05T21:35:48.193Z,1686000948.193 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2023-06-05T21:35:48.219Z,1686000948.219 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2023-06-05T21:35:48.230Z,1686000948.230 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2023-06-05T21:35:48.241Z,1686000948.241 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2023-06-05T21:35:48.248Z,1686000948.248 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2023-06-05T21:35:48.251Z,1686000948.251 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2023-06-05T21:35:48.261Z,1686000948.261 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2023-06-05T21:35:48.264Z,1686000948.264 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2023-06-05T21:35:48.267Z,1686000948.267 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2023-06-05T21:35:48.274Z,1686000948.274 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2023-06-05T21:35:48.278Z,1686000948.278 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2023-06-05T21:35:48.293Z,1686000948.293 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2023-06-05T21:35:48.300Z,1686000948.300 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2023-06-05T21:35:48.306Z,1686000948.306 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2023-06-05T21:35:48.317Z,1686000948.317 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2023-06-05T21:35:48.323Z,1686000948.323 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2023-06-05T21:35:48.338Z,1686000948.338 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2023-06-05T21:35:48.342Z,1686000948.342 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2023-06-05T21:35:48.353Z,1686000948.353 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2023-06-05T21:35:48.360Z,1686000948.360 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2023-06-05T21:35:48.368Z,1686000948.368 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2023-06-05T21:35:48.373Z,1686000948.373 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2023-06-05T21:35:48.377Z,1686000948.377 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2023-06-05T21:35:48.381Z,1686000948.381 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2023-06-05T21:35:48.384Z,1686000948.384 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2023-06-05T21:35:48.387Z,1686000948.387 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2023-06-05T21:35:48.390Z,1686000948.390 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2023-06-05T21:35:48.422Z,1686000948.422 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2023-06-05T21:35:48.425Z,1686000948.425 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2023-06-05T21:35:48.436Z,1686000948.436 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2023-06-05T21:35:48.483Z,1686000948.483 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-06-05T21:35:48.513Z,1686000948.513 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-06-05T21:35:48.547Z,1686000948.547 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-06-05T21:35:48.567Z,1686000948.567 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-06-05T21:35:48.643Z,1686000948.643 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-06-05T21:35:48.674Z,1686000948.674 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-06-05T21:35:48.695Z,1686000948.695 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-06-05T21:35:48.721Z,1686000948.721 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-06-05T21:35:48.747Z,1686000948.747 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2023-06-05T21:35:48.938Z,1686000948.938 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2023-06-05T21:35:48.953Z,1686000948.953 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2023-06-05T21:35:48.955Z,1686000948.955 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2023-06-05T21:35:48.962Z,1686000948.962 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2023-06-05T21:35:48.966Z,1686000948.966 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2023-06-05T21:35:49.009Z,1686000949.009 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2023-06-05T21:35:49.017Z,1686000949.017 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2023-06-05T21:35:49.040Z,1686000949.040 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2023-06-05T21:35:49.043Z,1686000949.043 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2023-06-05T21:35:49.050Z,1686000949.050 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2023-06-05T21:35:49.053Z,1686000949.053 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2023-06-05T21:35:49.065Z,1686000949.065 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2023-06-05T21:35:49.072Z,1686000949.072 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2023-06-05T21:35:49.075Z,1686000949.075 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2023-06-05T21:35:49.107Z,1686000949.107 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2023-06-05T21:35:49.119Z,1686000949.119 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-05T21:35:49.131Z,1686000949.131 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2023-06-05T21:35:49.157Z,1686000949.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2023-06-05T21:35:49.161Z,1686000949.161 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2023-06-05T21:35:49.168Z,1686000949.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2023-06-05T21:35:49.184Z,1686000949.184 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2023-06-05T21:35:49.187Z,1686000949.187 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2023-06-05T21:35:49.195Z,1686000949.195 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2023-06-05T21:35:49.218Z,1686000949.218 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2023-06-05T21:35:49.234Z,1686000949.234 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2023-06-05T21:35:49.295Z,1686000949.295 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2023-06-05T21:35:49.297Z,1686000949.297 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2023-06-05T21:35:49.298Z,1686000949.298 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2023-06-05T21:35:49.300Z,1686000949.300 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2023-06-05T21:35:49.302Z,1686000949.302 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2023-06-05T21:35:49.314Z,1686000949.314 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2023-06-05T21:35:49.316Z,1686000949.316 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2023-06-05T21:35:49.317Z,1686000949.317 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2023-06-05T21:35:49.405Z,1686000949.405 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-05T21:35:49.416Z,1686000949.416 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2023-06-05T21:35:49.489Z,1686000949.489 [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>


2023-06-05T21:35:49.489Z,1686000949.489 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/tank_ballast_and_trim.xml
2023-06-05T21:35:52.910Z,1686000952.910 [CommandExec](IMPORTANT): got command set ballast_and_trim.EstimationConfidence 98 percent
2023-06-05T21:35:52.911Z,1686000952.911 [CommandExec](IMPORTANT): got command run
2023-06-05T21:35:52.915Z,1686000952.915 [CommandExec](IMPORTANT): Running 
2023-06-05T21:35:53.047Z,1686000953.047 [Default] Stopped
2023-06-05T21:35:53.047Z,1686000953.047 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-05T21:35:53.047Z,1686000953.047 [Default:B.GoToSurface] Stopped
2023-06-05T21:35:53.047Z,1686000953.047 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-05T21:35:53.047Z,1686000953.047 [Default:CheckIn] Stopped
2023-06-05T21:35:53.052Z,1686000953.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T21:35:53.052Z,1686000953.052 [Default:CheckIn:C.Wait] Stopped
2023-06-05T21:35:53.052Z,1686000953.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:35:53.052Z,1686000953.052 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2023-06-05T21:35:53.052Z,1686000953.052 [ballast_and_trim] Running Loop=1
2023-06-05T21:35:53.052Z,1686000953.052 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2023-06-05T21:35:53.052Z,1686000953.052 [ballast_and_trim:Science] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:A] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:B] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:C] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:D] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:E] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:F] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2023-06-05T21:35:53.053Z,1686000953.053 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-06-05T21:35:53.055Z,1686000953.055 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2023-06-05T21:35:53.055Z,1686000953.055 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2023-06-05T21:35:53.060Z,1686000953.060 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-06-05T21:35:53.060Z,1686000953.060 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-06-05T21:35:53.060Z,1686000953.060 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2023-06-05T21:35:53.060Z,1686000953.060 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2023-06-05T21:35:53.061Z,1686000953.061 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2023-06-05T21:35:53.061Z,1686000953.061 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-06-05T21:35:53.063Z,1686000953.063 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2023-06-05T21:35:53.063Z,1686000953.063 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2023-06-05T21:35:53.063Z,1686000953.063 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2023-06-05T21:35:53.063Z,1686000953.063 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-06-05T21:35:53.069Z,1686000953.069 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2023-06-05T21:35:53.069Z,1686000953.069 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2023-06-05T21:35:53.069Z,1686000953.069 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-06-05T21:35:53.069Z,1686000953.069 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-06-05T21:35:53.070Z,1686000953.070 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2023-06-05T21:35:53.070Z,1686000953.070 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2023-06-05T21:35:53.070Z,1686000953.070 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2023-06-05T21:35:53.070Z,1686000953.070 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-06-05T21:35:53.072Z,1686000953.072 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2023-06-05T21:35:53.072Z,1686000953.072 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2023-06-05T21:35:53.072Z,1686000953.072 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2023-06-05T21:35:53.072Z,1686000953.072 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-06-05T21:35:53.074Z,1686000953.074 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2023-06-05T21:35:53.074Z,1686000953.074 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2023-06-05T21:35:53.074Z,1686000953.074 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-06-05T21:35:53.074Z,1686000953.074 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2023-06-05T21:35:53.075Z,1686000953.075 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2023-06-05T21:35:53.084Z,1686000953.084 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2023-06-05T21:35:53.084Z,1686000953.084 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-06-05T21:35:53.084Z,1686000953.084 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2023-06-05T21:35:53.085Z,1686000953.085 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2023-06-05T21:35:53.085Z,1686000953.085 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2023-06-05T21:35:53.085Z,1686000953.085 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-06-05T21:35:53.085Z,1686000953.085 [ballast_and_trim:Science] Running Loop=1
2023-06-05T21:35:53.086Z,1686000953.086 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2023-06-05T21:35:53.086Z,1686000953.086 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-06-05T21:35:53.087Z,1686000953.087 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectOil] Stopped
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2023-06-05T21:35:53.092Z,1686000953.092 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:PeakDetectChl] Stopped
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-06-05T21:35:53.093Z,1686000953.093 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-06-05T21:35:53.094Z,1686000953.094 [ballast_and_trim:Science:Read_Oil] Stopped
2023-06-05T21:35:53.094Z,1686000953.094 [ballast_and_trim:Science:F] Stopped
2023-06-05T21:35:53.094Z,1686000953.094 [ballast_and_trim:Science:E] Running Loop=1
2023-06-05T21:35:53.094Z,1686000953.094 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2023-06-05T21:35:53.094Z,1686000953.094 [ballast_and_trim:Science:D] Stopped
2023-06-05T21:35:53.095Z,1686000953.095 [ballast_and_trim:Science:C] Running Loop=1
2023-06-05T21:35:53.095Z,1686000953.095 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2023-06-05T21:35:53.097Z,1686000953.097 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2023-06-05T21:35:53.097Z,1686000953.097 [ballast_and_trim:Science:B] Running Loop=1
2023-06-05T21:35:53.097Z,1686000953.097 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2023-06-05T21:35:53.098Z,1686000953.098 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2023-06-05T21:35:53.098Z,1686000953.098 [ballast_and_trim:Science:A] Stopped
2023-06-05T21:35:53.417Z,1686000953.417 [WetLabsBB2FL](INFO): Powering up
2023-06-05T21:35:53.472Z,1686000953.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2023-06-05T21:35:53.472Z,1686000953.472 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-06-05T21:35:53.473Z,1686000953.473 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-06-05T21:35:53.475Z,1686000953.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2023-06-05T21:35:53.476Z,1686000953.476 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-06-05T21:35:53.477Z,1686000953.477 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-06-05T21:35:53.854Z,1686000953.854 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2023-06-05T21:35:53.854Z,1686000953.854 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2023-06-05T21:35:53.855Z,1686000953.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2023-06-05T21:35:54.262Z,1686000954.262 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-06-05T21:35:54.263Z,1686000954.263 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-06-05T21:35:54.263Z,1686000954.263 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2023-06-05T21:35:54.263Z,1686000954.263 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2023-06-05T21:35:54.681Z,1686000954.681 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-06-05T21:35:54.681Z,1686000954.681 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2023-06-05T21:35:54.681Z,1686000954.681 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2023-06-05T21:35:54.682Z,1686000954.682 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2023-06-05T21:35:54.682Z,1686000954.682 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2023-06-05T21:35:56.617Z,1686000956.617 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2023-06-05T21:35:58.626Z,1686000958.626 [CTD_Seabird](ERROR): Salinity reading out of range: 21.350969 psu
2023-06-05T21:36:39.087Z,1686000999.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T21:36:39.087Z,1686000999.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T21:37:42.504Z,1686001062.504 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T21:38:13.496Z,1686001093.496 [Radio_Surface](INFO): Powering down
2023-06-05T21:38:13.628Z,1686001093.628 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T21:38:14.632Z,1686001094.632 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-06-05T21:38:31.810Z,1686001111.810 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T21:39:02.513Z,1686001142.513 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T21:39:14.641Z,1686001154.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-06-05T21:39:14.642Z,1686001154.642 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-06-05T21:39:14.643Z,1686001154.643 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2023-06-05T21:39:14.644Z,1686001154.644 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2023-06-05T21:39:15.055Z,1686001155.055 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.043755 m 
2023-06-05T21:39:15.055Z,1686001155.055 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2023-06-05T21:39:15.055Z,1686001155.055 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2023-06-05T21:39:15.055Z,1686001155.055 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:39:15.055Z,1686001155.055 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-06-05T21:39:15.060Z,1686001155.060 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-06-05T21:39:51.076Z,1686001191.076 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.799194
2023-06-05T21:49:15.794Z,1686001755.794 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2023-06-05T21:49:15.794Z,1686001755.794 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2023-06-05T21:49:15.794Z,1686001755.794 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T21:49:15.795Z,1686001755.795 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2023-06-05T21:49:16.204Z,1686001756.204 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 6.535967 m 
2023-06-05T21:49:16.204Z,1686001756.204 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2023-06-05T21:49:16.204Z,1686001756.204 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2023-06-05T21:49:16.204Z,1686001756.204 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2023-06-05T21:56:23.733Z,1686002183.733 [CTD_Seabird](ERROR): Failed to parse device response: .19
2023-06-05T21:59:16.956Z,1686002356.956 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 10.01 minutes.
2023-06-05T21:59:16.957Z,1686002356.957 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 233.035828 +/- 5.160662 cc (conf. level 98.00%, sigma: 27.307641 cc).
2023-06-05T21:59:16.958Z,1686002356.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: -10.313124 +/- 0.055133 mm (conf. level 98.00%, sigma: 0.291734 mm).
2023-06-05T21:59:16.958Z,1686002356.958 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 233.035828 cc buoyancy neutral and -10.313124 mm mass default
2023-06-05T21:59:16.963Z,1686002356.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-05T21:59:16.980Z,1686002356.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-06-05T21:59:16.980Z,1686002356.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BPC1.batteryMissingStickThreshold=14 count;

2023-06-05T21:59:16.980Z,1686002356.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-06-05T21:59:16.980Z,1686002356.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=233.035828 cubic_centimeter;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=-10.313124 millimeter;

2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2023-06-05T21:59:16.981Z,1686002356.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2023-06-05T21:59:16.982Z,1686002356.982 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-06-05T21:59:16.982Z,1686002356.982 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2023-06-05T21:59:16.983Z,1686002356.983 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-06-05T21:59:16.983Z,1686002356.983 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2023-06-05T21:59:16.983Z,1686002356.983 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2023-06-05T21:59:16.983Z,1686002356.983 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2023-06-05T21:59:16.984Z,1686002356.984 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2023-06-05T21:59:17.365Z,1686002357.365 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-06-05T21:59:17.366Z,1686002357.366 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim] Stopped
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2023-06-05T21:59:17.771Z,1686002357.771 [ballast_and_trim:Float_Up] Running Loop=1
2023-06-05T21:59:17.772Z,1686002357.772 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2023-06-05T21:59:17.772Z,1686002357.772 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-06-05T21:59:17.772Z,1686002357.772 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-05T21:59:17.772Z,1686002357.772 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2023-06-05T21:59:17.772Z,1686002357.772 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2023-06-05T21:59:18.188Z,1686002358.188 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up] Stopped
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up:B.Wait] Stopped
2023-06-05T22:01:20.183Z,1686002480.183 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:01:20.187Z,1686002480.187 [ballast_and_trim](INFO): Completed ballast_and_trim
2023-06-05T22:01:20.188Z,1686002480.188 [MissionManager](INFO): ballast_and_trim is completed.
2023-06-05T22:01:20.188Z,1686002480.188 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim] Stopped
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim:Science] Stopped
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim:Science:B] Stopped
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim:Science:C] Stopped
2023-06-05T22:01:20.188Z,1686002480.188 [ballast_and_trim:Science:E] Stopped
2023-06-05T22:01:20.190Z,1686002480.190 [ballast_and_trim:Science:OceanCurrent] Stopped
2023-06-05T22:01:20.190Z,1686002480.190 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2023-06-05T22:01:20.190Z,1686002480.190 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2023-06-05T22:01:20.460Z,1686002480.460 [WetLabsBB2FL](INFO): Powering down
2023-06-05T22:01:20.640Z,1686002480.640 [MissionManager](IMPORTANT): Started mission Default
2023-06-05T22:01:20.640Z,1686002480.640 [Default] Running Loop=1
2023-06-05T22:01:20.640Z,1686002480.640 [Default](DEBUG): Aggregate::initialize Default
2023-06-05T22:01:20.640Z,1686002480.640 [Default:B.GoToSurface] Running Loop=1
2023-06-05T22:01:20.640Z,1686002480.640 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-05T22:01:20.640Z,1686002480.640 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-05T22:01:20.641Z,1686002480.641 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-05T22:01:20.641Z,1686002480.641 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-05T22:01:20.641Z,1686002480.641 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-05T22:01:20.642Z,1686002480.642 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-05T22:01:20.642Z,1686002480.642 [Default:A.Wait] Running Loop=1
2023-06-05T22:01:20.642Z,1686002480.642 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:01:20.864Z,1686002480.864 [Radio_Surface](INFO): Powering up
2023-06-05T22:01:26.624Z,1686002486.624 [DataOverHttps](INFO): Radio surface powered ON.
2023-06-05T22:01:33.932Z,1686002493.932 [Default:A.Wait](INFO): Done Waiting.
2023-06-05T22:01:33.933Z,1686002493.933 [Default:A.Wait] Stopped
2023-06-05T22:01:33.933Z,1686002493.933 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:01:34.323Z,1686002494.323 [Default:CheckIn] Running Loop=1
2023-06-05T22:01:34.323Z,1686002494.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:01:34.323Z,1686002494.323 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:01:56.744Z,1686002516.744 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:02:07.037Z,1686002527.037 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T22:02:07.120Z,1686002527.120 [NAL9602](ERROR): received: 
+CSQ:0

OK354, 2, 0, 0, 0

OK
2023-06-05T22:02:27.892Z,1686002547.892 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:02:56.321Z,1686002576.321 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T22:02:56.321Z,1686002576.321 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T22:02:59.032Z,1686002579.032 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:03:30.164Z,1686002610.164 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:04:01.288Z,1686002641.288 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:04:32.452Z,1686002672.452 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T22:05:00.992Z,1686002700.992 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003067
2023-06-05T22:06:34.540Z,1686002794.540 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-06-05T22:01:34.3Z
2023-06-05T22:06:34.540Z,1686002794.540 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:06:34.541Z,1686002794.541 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:06:38.601Z,1686002798.601 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:06:44.339Z,1686002804.339 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230605T204550/Courier0028.lzma
2023-06-05T22:06:45.342Z,1686002805.342 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0028.lzma.bak
2023-06-05T22:06:45.342Z,1686002805.342 [DataOverHttps](INFO): SBD MOMSN=18397923
2023-06-05T22:07:01.013Z,1686002821.013 [DataOverHttps](INFO): Sending 1222 bytes from file Logs/20230605T204550/Express0029.lzma
2023-06-05T22:07:02.014Z,1686002822.014 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0029.lzma.bak
2023-06-05T22:07:02.014Z,1686002822.014 [DataOverHttps](INFO): SBD MOMSN=18397925
2023-06-05T22:07:09.377Z,1686002829.377 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T22:07:20.743Z,1686002840.743 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230605T204550/Express0032.lzma
2023-06-05T22:07:21.746Z,1686002841.746 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0032.lzma.bak
2023-06-05T22:07:21.746Z,1686002841.746 [DataOverHttps](INFO): SBD MOMSN=18397950
2023-06-05T22:07:23.135Z,1686002843.135 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:07:23.136Z,1686002843.136 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:07:23.136Z,1686002843.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:12:23.709Z,1686003143.709 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:12:23.709Z,1686003143.709 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:12:23.709Z,1686003143.709 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:12:23.710Z,1686003143.710 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:12:24.115Z,1686003144.115 [Default:CheckIn:D] Stopped
2023-06-05T22:12:24.115Z,1686003144.115 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:12:24.527Z,1686003144.527 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.057919 min 
2023-06-05T22:12:24.527Z,1686003144.527 [Default:CheckIn:E] Stopped
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn] Stopped
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn](INFO): Running loop #2
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn] Running Loop=2
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:12:24.528Z,1686003144.528 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:12:26.129Z,1686003146.129 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-06-05T22:12:26.129Z,1686003146.129 [NAL9602] Data Fault, FailCount= 1
2023-06-05T22:12:26.129Z,1686003146.129 [NAL9602](ERROR): Data Fault
2023-06-05T22:12:26.199Z,1686003146.199 [CBIT](ERROR): Data Fault in component: NAL9602
2023-06-05T22:12:26.533Z,1686003146.533 [NAL9602](INFO): Powering down
2023-06-05T22:12:27.356Z,1686003147.356 [CBIT](INFO): Clearing failed state for component NAL9602
2023-06-05T22:12:27.356Z,1686003147.356 [NAL9602] No Fault, FailCount= 1
2023-06-05T22:12:56.828Z,1686003176.828 [NAL9602](INFO): Powering up NAL9602
2023-06-05T22:13:07.736Z,1686003187.736 [NAL9602](INFO): NAL9602 initialized
2023-06-05T22:17:24.754Z,1686003444.754 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-06-05T22:12:24.5Z
2023-06-05T22:17:24.754Z,1686003444.754 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:17:24.754Z,1686003444.754 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:17:32.547Z,1686003452.547 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230605T204550/Courier0034.lzma
2023-06-05T22:17:33.550Z,1686003453.550 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0034.lzma.bak
2023-06-05T22:17:33.550Z,1686003453.550 [DataOverHttps](INFO): SBD MOMSN=18398003
2023-06-05T22:17:49.752Z,1686003469.752 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20230605T204550/Express0035.lzma
2023-06-05T22:17:50.754Z,1686003470.754 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0035.lzma.bak
2023-06-05T22:17:50.754Z,1686003470.754 [DataOverHttps](INFO): SBD MOMSN=18398005
2023-06-05T22:17:52.256Z,1686003472.256 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:17:52.257Z,1686003472.257 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:17:52.257Z,1686003472.257 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:18:11.233Z,1686003491.233 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:18:41.908Z,1686003521.908 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T22:19:31.260Z,1686003571.260 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-06-05T22:21:58.675Z,1686003718.675 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:22:13.602Z,1686003733.602 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:22:28.550Z,1686003748.550 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:22:43.914Z,1686003763.914 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:22:52.833Z,1686003772.833 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:22:52.833Z,1686003772.833 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:22:52.833Z,1686003772.833 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:22:52.833Z,1686003772.833 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:22:53.223Z,1686003773.223 [Default:CheckIn:D] Stopped
2023-06-05T22:22:53.223Z,1686003773.223 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:22:53.691Z,1686003773.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.543050 min 
2023-06-05T22:22:53.691Z,1686003773.691 [Default:CheckIn:E] Stopped
2023-06-05T22:22:53.691Z,1686003773.691 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn] Stopped
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn](INFO): Running loop #3
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn] Running Loop=3
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:22:53.692Z,1686003773.692 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:22:55.635Z,1686003775.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222235.00,A,3648.16344,N,12147.28619,W,0.117,187.00,050623,,,A*79
2023-06-05T22:22:55.638Z,1686003775.638 [NAL9602](INFO): GPS fix at 20230605T222235: (36.802724, -121.788103)
2023-06-05T22:22:55.652Z,1686003775.652 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:22:55.652Z,1686003775.652 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:22:59.673Z,1686003779.673 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:23:03.171Z,1686003783.171 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0037.lzma
2023-06-05T22:23:04.174Z,1686003784.174 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0037.lzma.bak
2023-06-05T22:23:04.174Z,1686003784.174 [DataOverHttps](INFO): SBD MOMSN=18398012
2023-06-05T22:23:14.686Z,1686003794.686 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:23:23.071Z,1686003803.071 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230605T204550/Express0038.lzma
2023-06-05T22:23:24.074Z,1686003804.074 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0038.lzma.bak
2023-06-05T22:23:24.074Z,1686003804.074 [DataOverHttps](INFO): SBD MOMSN=18398015
2023-06-05T22:23:25.617Z,1686003805.617 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:23:25.617Z,1686003805.617 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:23:25.618Z,1686003805.618 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:23:30.044Z,1686003810.044 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:23:45.393Z,1686003825.393 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:24:00.742Z,1686003840.742 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:24:15.286Z,1686003855.286 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-05T22:26:47.690Z,1686004007.690 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-06-05T22:27:57.977Z,1686004077.977 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:28:26.268Z,1686004106.268 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:28:26.268Z,1686004106.268 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:28:26.268Z,1686004106.268 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:28:26.268Z,1686004106.268 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:28:26.671Z,1686004106.671 [Default:CheckIn:D] Stopped
2023-06-05T22:28:26.671Z,1686004106.671 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.100515 min 
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn:E] Stopped
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn] Stopped
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn](INFO): Running loop #4
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn] Running Loop=4
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:28:27.084Z,1686004107.084 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:28:29.087Z,1686004109.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222810.00,A,3648.16408,N,12147.28343,W,0.350,50.84,050623,,,A*47
2023-06-05T22:28:29.089Z,1686004109.089 [NAL9602](INFO): GPS fix at 20230605T222810: (36.802735, -121.788057)
2023-06-05T22:28:29.100Z,1686004109.100 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:28:29.100Z,1686004109.100 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:28:37.271Z,1686004117.271 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0040.lzma
2023-06-05T22:28:38.274Z,1686004118.274 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0040.lzma.bak
2023-06-05T22:28:38.274Z,1686004118.274 [DataOverHttps](INFO): SBD MOMSN=18398027
2023-06-05T22:28:57.120Z,1686004137.120 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230605T204550/Express0041.lzma
2023-06-05T22:28:58.122Z,1686004138.122 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0041.lzma.bak
2023-06-05T22:28:58.122Z,1686004138.122 [DataOverHttps](INFO): SBD MOMSN=18398030
2023-06-05T22:28:59.449Z,1686004139.449 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:28:59.449Z,1686004139.449 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:28:59.449Z,1686004139.449 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:29:01.877Z,1686004141.877 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T22:31:27.755Z,1686004287.755 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:31:34.625Z,1686004294.625 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:31:41.085Z,1686004301.085 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2023-06-05T22:31:41.090Z,1686004301.090 [BPC1](INFO): Calculating totals. Valid battery stick count: 44. Valid reserve battery stick count: 5.
2023-06-05T22:31:41.094Z,1686004301.094 [BPC1](INFO): Received data from all battery sticks.
2023-06-05T22:34:00.175Z,1686004440.175 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:34:00.175Z,1686004440.175 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:34:00.175Z,1686004440.175 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:34:00.176Z,1686004440.176 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:34:00.570Z,1686004440.570 [Default:CheckIn:D] Stopped
2023-06-05T22:34:00.570Z,1686004440.570 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.665505 min 
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn:E] Stopped
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn] Stopped
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn](INFO): Running loop #5
2023-06-05T22:34:00.972Z,1686004440.972 [Default:CheckIn] Running Loop=5
2023-06-05T22:34:00.973Z,1686004440.973 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:34:00.973Z,1686004440.973 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:34:02.987Z,1686004442.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223343.00,A,3648.16584,N,12147.28195,W,0.641,50.84,050623,,,A*42
2023-06-05T22:34:02.998Z,1686004442.998 [NAL9602](INFO): GPS fix at 20230605T223343: (36.802764, -121.788032)
2023-06-05T22:34:03.012Z,1686004443.012 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:34:03.012Z,1686004443.012 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:34:09.859Z,1686004449.859 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230605T204550/Courier0043.lzma
2023-06-05T22:34:10.862Z,1686004450.862 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0043.lzma.bak
2023-06-05T22:34:10.862Z,1686004450.862 [DataOverHttps](INFO): SBD MOMSN=18398036
2023-06-05T22:34:26.727Z,1686004466.727 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230605T204550/Express0044.lzma
2023-06-05T22:34:27.730Z,1686004467.730 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0044.lzma.bak
2023-06-05T22:34:27.730Z,1686004467.730 [DataOverHttps](INFO): SBD MOMSN=18398041
2023-06-05T22:34:29.260Z,1686004469.260 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:34:29.261Z,1686004469.261 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:34:29.261Z,1686004469.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:39:05.649Z,1686004745.649 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:39:29.967Z,1686004769.967 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:39:29.967Z,1686004769.967 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:39:29.967Z,1686004769.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:39:29.968Z,1686004769.968 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:39:30.364Z,1686004770.364 [Default:CheckIn:D] Stopped
2023-06-05T22:39:30.364Z,1686004770.364 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.162069 min 
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn:E] Stopped
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn] Stopped
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn](INFO): Running loop #6
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn] Running Loop=6
2023-06-05T22:39:30.778Z,1686004770.778 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:39:30.779Z,1686004770.779 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:39:32.782Z,1686004772.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223913.00,A,3648.15862,N,12147.28148,W,0.058,50.84,050623,,,A*45
2023-06-05T22:39:32.784Z,1686004772.784 [NAL9602](INFO): GPS fix at 20230605T223913: (36.802644, -121.788025)
2023-06-05T22:39:32.794Z,1686004772.794 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:39:32.795Z,1686004772.795 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:39:40.107Z,1686004780.107 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0046.lzma
2023-06-05T22:39:41.110Z,1686004781.110 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0046.lzma.bak
2023-06-05T22:39:41.110Z,1686004781.110 [DataOverHttps](INFO): SBD MOMSN=18398076
2023-06-05T22:39:56.987Z,1686004796.987 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230605T204550/Express0047.lzma
2023-06-05T22:39:57.990Z,1686004797.990 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0047.lzma.bak
2023-06-05T22:39:57.990Z,1686004797.990 [DataOverHttps](INFO): SBD MOMSN=18398079
2023-06-05T22:39:59.447Z,1686004799.447 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:39:59.447Z,1686004799.447 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:39:59.447Z,1686004799.447 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:40:04.687Z,1686004804.687 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T22:45:00.126Z,1686005100.126 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:45:00.126Z,1686005100.126 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:45:00.126Z,1686005100.126 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:45:00.127Z,1686005100.127 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:45:00.527Z,1686005100.527 [Default:CheckIn:D] Stopped
2023-06-05T22:45:00.527Z,1686005100.527 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:45:00.931Z,1686005100.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.664783 min 
2023-06-05T22:45:00.931Z,1686005100.931 [Default:CheckIn:E] Stopped
2023-06-05T22:45:00.931Z,1686005100.931 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:45:00.931Z,1686005100.931 [Default:CheckIn] Stopped
2023-06-05T22:45:00.932Z,1686005100.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:45:00.932Z,1686005100.932 [Default:CheckIn](INFO): Running loop #7
2023-06-05T22:45:00.932Z,1686005100.932 [Default:CheckIn] Running Loop=7
2023-06-05T22:45:00.933Z,1686005100.933 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:45:00.933Z,1686005100.933 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:45:02.943Z,1686005102.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224443.00,A,3648.16294,N,12147.28195,W,0.058,0.00,050623,,,A*73
2023-06-05T22:45:02.945Z,1686005102.945 [NAL9602](INFO): GPS fix at 20230605T224443: (36.802716, -121.788032)
2023-06-05T22:45:02.969Z,1686005102.969 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:45:02.969Z,1686005102.969 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:45:13.184Z,1686005113.184 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0049.lzma
2023-06-05T22:45:14.186Z,1686005114.186 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0049.lzma.bak
2023-06-05T22:45:14.186Z,1686005114.186 [DataOverHttps](INFO): SBD MOMSN=18398102
2023-06-05T22:45:30.035Z,1686005130.035 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230605T204550/Express0050.lzma
2023-06-05T22:45:31.038Z,1686005131.038 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0050.lzma.bak
2023-06-05T22:45:31.038Z,1686005131.038 [DataOverHttps](INFO): SBD MOMSN=18398105
2023-06-05T22:45:32.524Z,1686005132.524 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:45:32.525Z,1686005132.525 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:45:32.525Z,1686005132.525 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:45:33.712Z,1686005133.712 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T22:45:33.792Z,1686005133.792 [NAL9602](ERROR): received: 
+CSQ:0

OK354, 2, 0, 0, 0

OK
2023-06-05T22:50:05.437Z,1686005405.437 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:50:32.933Z,1686005432.933 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:50:32.933Z,1686005432.933 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:50:32.933Z,1686005432.933 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:50:32.933Z,1686005432.933 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:50:33.323Z,1686005433.323 [Default:CheckIn:D] Stopped
2023-06-05T22:50:33.323Z,1686005433.323 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:50:33.726Z,1686005433.726 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.211377 min 
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn:E] Stopped
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn] Stopped
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn](INFO): Running loop #8
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn] Running Loop=8
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:50:33.727Z,1686005433.727 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:50:35.739Z,1686005435.739 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225016.00,A,3648.16295,N,12147.28424,W,0.272,0.00,050623,,,A*72
2023-06-05T22:50:35.749Z,1686005435.749 [NAL9602](INFO): GPS fix at 20230605T225016: (36.802716, -121.788071)
2023-06-05T22:50:35.760Z,1686005435.760 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:50:35.760Z,1686005435.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:50:46.311Z,1686005446.311 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0052.lzma
2023-06-05T22:50:47.314Z,1686005447.314 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0052.lzma.bak
2023-06-05T22:50:47.314Z,1686005447.314 [DataOverHttps](INFO): SBD MOMSN=18398110
2023-06-05T22:51:03.145Z,1686005463.145 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230605T204550/Express0053.lzma
2023-06-05T22:51:04.146Z,1686005464.146 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0053.lzma.bak
2023-06-05T22:51:04.146Z,1686005464.146 [DataOverHttps](INFO): SBD MOMSN=18398116
2023-06-05T22:51:05.705Z,1686005465.705 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:51:05.706Z,1686005465.706 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:51:05.706Z,1686005465.706 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:51:07.741Z,1686005467.741 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T22:56:06.465Z,1686005766.465 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:56:06.465Z,1686005766.465 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:56:06.465Z,1686005766.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:56:06.465Z,1686005766.465 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:56:06.858Z,1686005766.858 [Default:CheckIn:D] Stopped
2023-06-05T22:56:06.858Z,1686005766.858 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.770296 min 
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn:E] Stopped
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn] Stopped
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:56:07.267Z,1686005767.267 [Default:CheckIn](INFO): Running loop #9
2023-06-05T22:56:07.268Z,1686005767.268 [Default:CheckIn] Running Loop=9
2023-06-05T22:56:07.268Z,1686005767.268 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:56:07.268Z,1686005767.268 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:56:09.282Z,1686005769.282 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225550.00,A,3648.16054,N,12147.28125,W,0.525,0.00,050623,,,A*7B
2023-06-05T22:56:09.284Z,1686005769.284 [NAL9602](INFO): GPS fix at 20230605T225550: (36.802676, -121.788021)
2023-06-05T22:56:09.295Z,1686005769.295 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:56:09.295Z,1686005769.295 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:56:16.959Z,1686005776.959 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0055.lzma
2023-06-05T22:56:17.962Z,1686005777.962 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0055.lzma.bak
2023-06-05T22:56:17.962Z,1686005777.962 [DataOverHttps](INFO): SBD MOMSN=18398125
2023-06-05T22:56:33.819Z,1686005793.819 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230605T204550/Express0056.lzma
2023-06-05T22:56:34.822Z,1686005794.822 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0056.lzma.bak
2023-06-05T22:56:34.822Z,1686005794.822 [DataOverHttps](INFO): SBD MOMSN=18398128
2023-06-05T22:56:36.400Z,1686005796.400 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:56:36.400Z,1686005796.400 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:56:36.400Z,1686005796.400 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:56:40.033Z,1686005800.033 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T22:56:40.112Z,1686005800.112 [NAL9602](ERROR): received: 
+CSQ:0

OK354, 2, 0, 0, 0

OK
2023-06-05T23:00:11.042Z,1686006011.042 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T23:00:11.042Z,1686006011.042 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T23:00:41.335Z,1686006041.335 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T23:00:41.335Z,1686006041.335 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T23:01:11.634Z,1686006071.634 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T23:01:37.098Z,1686006097.098 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:01:37.099Z,1686006097.099 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:01:37.099Z,1686006097.099 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:01:37.099Z,1686006097.099 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:01:37.517Z,1686006097.517 [Default:CheckIn:D] Stopped
2023-06-05T23:01:37.517Z,1686006097.517 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:01:37.907Z,1686006097.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.281283 min 
2023-06-05T23:01:37.907Z,1686006097.907 [Default:CheckIn:E] Stopped
2023-06-05T23:01:37.907Z,1686006097.907 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:01:37.907Z,1686006097.907 [Default:CheckIn] Stopped
2023-06-05T23:01:37.907Z,1686006097.907 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:01:37.908Z,1686006097.908 [Default:CheckIn](INFO): Running loop #10
2023-06-05T23:01:37.908Z,1686006097.908 [Default:CheckIn] Running Loop=10
2023-06-05T23:01:37.908Z,1686006097.908 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:01:37.908Z,1686006097.908 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:01:39.915Z,1686006099.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230120.00,A,3648.16505,N,12147.28476,W,0.778,130.04,050623,,,A*72
2023-06-05T23:01:39.918Z,1686006099.918 [NAL9602](INFO): GPS fix at 20230605T230120: (36.802751, -121.788079)
2023-06-05T23:01:39.928Z,1686006099.928 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:01:39.928Z,1686006099.928 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:01:47.791Z,1686006107.791 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0058.lzma
2023-06-05T23:01:48.794Z,1686006108.794 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0058.lzma.bak
2023-06-05T23:01:48.794Z,1686006108.794 [DataOverHttps](INFO): SBD MOMSN=18398141
2023-06-05T23:02:04.548Z,1686006124.548 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230605T204550/Express0059.lzma
2023-06-05T23:02:05.550Z,1686006125.550 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0059.lzma.bak
2023-06-05T23:02:05.550Z,1686006125.550 [DataOverHttps](INFO): SBD MOMSN=18398144
2023-06-05T23:02:06.997Z,1686006126.997 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:02:06.997Z,1686006126.997 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:02:06.997Z,1686006126.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:02:11.829Z,1686006131.829 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T23:07:07.734Z,1686006427.734 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:07:07.734Z,1686006427.734 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:07:07.734Z,1686006427.734 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:07:07.735Z,1686006427.735 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:07:08.230Z,1686006428.230 [Default:CheckIn:D] Stopped
2023-06-05T23:07:08.230Z,1686006428.230 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:07:08.544Z,1686006428.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.793160 min 
2023-06-05T23:07:08.544Z,1686006428.544 [Default:CheckIn:E] Stopped
2023-06-05T23:07:08.544Z,1686006428.544 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:07:08.544Z,1686006428.544 [Default:CheckIn] Stopped
2023-06-05T23:07:08.544Z,1686006428.544 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:07:08.545Z,1686006428.545 [Default:CheckIn](INFO): Running loop #11
2023-06-05T23:07:08.545Z,1686006428.545 [Default:CheckIn] Running Loop=11
2023-06-05T23:07:08.545Z,1686006428.545 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:07:08.545Z,1686006428.545 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:07:10.547Z,1686006430.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230651.00,A,3648.16538,N,12147.28472,W,0.136,130.04,050623,,,A*75
2023-06-05T23:07:10.549Z,1686006430.549 [NAL9602](INFO): GPS fix at 20230605T230651: (36.802756, -121.788079)
2023-06-05T23:07:10.706Z,1686006430.706 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:07:10.706Z,1686006430.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:07:18.615Z,1686006438.615 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0061.lzma
2023-06-05T23:07:19.618Z,1686006439.618 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0061.lzma.bak
2023-06-05T23:07:19.618Z,1686006439.618 [DataOverHttps](INFO): SBD MOMSN=18398182
2023-06-05T23:07:35.395Z,1686006455.395 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230605T204550/Express0062.lzma
2023-06-05T23:07:36.398Z,1686006456.398 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0062.lzma.bak
2023-06-05T23:07:36.398Z,1686006456.398 [DataOverHttps](INFO): SBD MOMSN=18398185
2023-06-05T23:07:37.793Z,1686006457.793 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:07:37.793Z,1686006457.793 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:07:37.793Z,1686006457.793 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:07:41.005Z,1686006461.005 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T23:07:41.080Z,1686006461.080 [NAL9602](ERROR): received: 
+CSQ:0

OK354, 2, 0, 0, 0

OK
2023-06-05T23:10:30.812Z,1686006630.812 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T23:10:30.812Z,1686006630.812 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T23:11:51.230Z,1686006711.230 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T23:11:51.230Z,1686006711.230 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T23:12:08.604Z,1686006728.604 [NAL9602](INFO): SBD MO Status=2, MOMSN=43354, MT Status=2, MTMSN=0
2023-06-05T23:12:08.604Z,1686006728.604 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-05T23:12:12.641Z,1686006732.641 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T23:12:38.513Z,1686006758.513 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:12:38.514Z,1686006758.514 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:12:38.514Z,1686006758.514 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:12:38.514Z,1686006758.514 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:12:38.922Z,1686006758.922 [Default:CheckIn:D] Stopped
2023-06-05T23:12:38.922Z,1686006758.922 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:12:39.311Z,1686006759.311 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.304696 min 
2023-06-05T23:12:39.311Z,1686006759.311 [Default:CheckIn:E] Stopped
2023-06-05T23:12:39.311Z,1686006759.311 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:12:39.311Z,1686006759.311 [Default:CheckIn] Stopped
2023-06-05T23:12:39.311Z,1686006759.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:12:39.312Z,1686006759.312 [Default:CheckIn](INFO): Running loop #12
2023-06-05T23:12:39.312Z,1686006759.312 [Default:CheckIn] Running Loop=12
2023-06-05T23:12:39.312Z,1686006759.312 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:12:39.312Z,1686006759.312 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:12:41.336Z,1686006761.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231222.00,A,3648.16122,N,12147.28242,W,0.350,342.20,050623,,,A*7D
2023-06-05T23:12:41.338Z,1686006761.338 [NAL9602](INFO): GPS fix at 20230605T231222: (36.802687, -121.788040)
2023-06-05T23:12:41.349Z,1686006761.349 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:12:41.349Z,1686006761.349 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:12:48.311Z,1686006768.311 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0064.lzma
2023-06-05T23:12:49.314Z,1686006769.314 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0064.lzma.bak
2023-06-05T23:12:49.314Z,1686006769.314 [DataOverHttps](INFO): SBD MOMSN=18398199
2023-06-05T23:13:04.972Z,1686006784.972 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230605T204550/Express0065.lzma
2023-06-05T23:13:05.974Z,1686006785.974 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0065.lzma.bak
2023-06-05T23:13:05.974Z,1686006785.974 [DataOverHttps](INFO): SBD MOMSN=18398202
2023-06-05T23:13:07.601Z,1686006787.601 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:13:07.602Z,1686006787.602 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:13:07.602Z,1686006787.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:13:13.697Z,1686006793.697 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T23:18:08.391Z,1686007088.391 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:18:08.391Z,1686007088.391 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:18:08.392Z,1686007088.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:18:08.392Z,1686007088.392 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:18:08.773Z,1686007088.773 [Default:CheckIn:D] Stopped
2023-06-05T23:18:08.773Z,1686007088.773 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:18:09.182Z,1686007089.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.802222 min 
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn:E] Stopped
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn] Stopped
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn](INFO): Running loop #13
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn] Running Loop=13
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:18:09.183Z,1686007089.183 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:18:11.190Z,1686007091.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231752.00,A,3648.16777,N,12147.28204,W,0.156,335.20,050623,,,A*7F
2023-06-05T23:18:11.192Z,1686007091.192 [NAL9602](INFO): GPS fix at 20230605T231752: (36.802796, -121.788034)
2023-06-05T23:18:11.206Z,1686007091.206 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:18:11.206Z,1686007091.206 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:18:18.671Z,1686007098.671 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0067.lzma
2023-06-05T23:18:19.674Z,1686007099.674 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0067.lzma.bak
2023-06-05T23:18:19.674Z,1686007099.674 [DataOverHttps](INFO): SBD MOMSN=18398219
2023-06-05T23:18:35.443Z,1686007115.443 [DataOverHttps](INFO): Sending 126 bytes from file Logs/20230605T204550/Express0068.lzma
2023-06-05T23:18:36.447Z,1686007116.447 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0068.lzma.bak
2023-06-05T23:18:36.447Z,1686007116.447 [DataOverHttps](INFO): SBD MOMSN=18398222
2023-06-05T23:18:38.274Z,1686007118.274 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:18:38.274Z,1686007118.274 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:18:38.274Z,1686007118.274 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:18:41.921Z,1686007121.921 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T23:18:42.004Z,1686007122.004 [NAL9602](ERROR): received: 
+SBDI: 2, 43354, 2, 0, 0, 0

OK
2023-06-05T23:23:13.905Z,1686007393.905 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T23:23:38.978Z,1686007418.978 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:23:38.978Z,1686007418.978 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:23:38.978Z,1686007418.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:23:38.978Z,1686007418.978 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:23:39.362Z,1686007419.362 [Default:CheckIn:D] Stopped
2023-06-05T23:23:39.362Z,1686007419.362 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:23:39.767Z,1686007419.767 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.312020 min 
2023-06-05T23:23:39.767Z,1686007419.767 [Default:CheckIn:E] Stopped
2023-06-05T23:23:39.767Z,1686007419.767 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:23:39.767Z,1686007419.767 [Default:CheckIn] Stopped
2023-06-05T23:23:39.768Z,1686007419.768 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:23:39.768Z,1686007419.768 [Default:CheckIn](INFO): Running loop #14
2023-06-05T23:23:39.768Z,1686007419.768 [Default:CheckIn] Running Loop=14
2023-06-05T23:23:39.768Z,1686007419.768 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:23:39.768Z,1686007419.768 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:23:41.779Z,1686007421.779 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232322.00,A,3648.16729,N,12147.28293,W,0.700,346.24,050623,,,D*7A
2023-06-05T23:23:41.781Z,1686007421.781 [NAL9602](INFO): GPS fix at 20230605T232322: (36.802788, -121.788049)
2023-06-05T23:23:41.812Z,1686007421.812 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:23:41.812Z,1686007421.812 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:23:49.203Z,1686007429.203 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0070.lzma
2023-06-05T23:23:50.206Z,1686007430.206 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0070.lzma.bak
2023-06-05T23:23:50.206Z,1686007430.206 [DataOverHttps](INFO): SBD MOMSN=18398249
2023-06-05T23:24:05.983Z,1686007445.983 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230605T204550/Express0071.lzma
2023-06-05T23:24:06.986Z,1686007446.986 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0071.lzma.bak
2023-06-05T23:24:06.986Z,1686007446.986 [DataOverHttps](INFO): SBD MOMSN=18398252
2023-06-05T23:24:08.450Z,1686007448.450 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:24:08.450Z,1686007448.450 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:24:08.450Z,1686007448.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:24:13.691Z,1686007453.691 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T23:29:09.141Z,1686007749.141 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:29:09.141Z,1686007749.141 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:29:09.141Z,1686007749.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:29:09.142Z,1686007749.142 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:29:09.544Z,1686007749.544 [Default:CheckIn:D] Stopped
2023-06-05T23:29:09.544Z,1686007749.544 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:29:09.918Z,1686007749.918 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.814925 min 
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn:E] Stopped
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn] Stopped
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn](INFO): Running loop #15
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn] Running Loop=15
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:29:09.919Z,1686007749.919 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:29:11.944Z,1686007751.944 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232852.00,A,3648.16576,N,12147.28061,W,0.156,130.57,050623,,,A*76
2023-06-05T23:29:11.947Z,1686007751.947 [NAL9602](INFO): GPS fix at 20230605T232852: (36.802763, -121.788010)
2023-06-05T23:29:11.957Z,1686007751.957 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:29:11.957Z,1686007751.957 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:29:18.971Z,1686007758.971 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230605T204550/Courier0073.lzma
2023-06-05T23:29:19.974Z,1686007759.974 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0073.lzma.bak
2023-06-05T23:29:19.974Z,1686007759.974 [DataOverHttps](INFO): SBD MOMSN=18398308
2023-06-05T23:29:35.679Z,1686007775.679 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230605T204550/Express0074.lzma
2023-06-05T23:29:36.682Z,1686007776.682 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0074.lzma.bak
2023-06-05T23:29:36.682Z,1686007776.682 [DataOverHttps](INFO): SBD MOMSN=18398311
2023-06-05T23:29:38.314Z,1686007778.314 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:29:38.314Z,1686007778.314 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:29:38.314Z,1686007778.314 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:29:42.749Z,1686007782.749 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-05T23:29:42.832Z,1686007782.832 [NAL9602](ERROR): received: 
+CSQ:0

OK354, 2, 0, 0, 0

OK
2023-06-05T23:34:14.741Z,1686008054.741 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T23:34:39.052Z,1686008079.052 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:34:39.052Z,1686008079.052 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:34:39.052Z,1686008079.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:34:39.052Z,1686008079.052 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:34:39.415Z,1686008079.415 [Default:CheckIn:D] Stopped
2023-06-05T23:34:39.415Z,1686008079.415 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.312915 min 
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn:E] Stopped
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn] Stopped
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn](INFO): Running loop #16
2023-06-05T23:34:39.828Z,1686008079.828 [Default:CheckIn] Running Loop=16
2023-06-05T23:34:39.829Z,1686008079.829 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:34:39.829Z,1686008079.829 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:34:41.821Z,1686008081.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233422.00,A,3648.16721,N,12147.28346,W,0.914,130.57,050623,,,A*74
2023-06-05T23:34:41.823Z,1686008081.823 [NAL9602](INFO): GPS fix at 20230605T233422: (36.802787, -121.788058)
2023-06-05T23:34:41.862Z,1686008081.862 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:34:41.862Z,1686008081.862 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T23:34:49.485Z,1686008089.485 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230605T204550/Courier0076.lzma
2023-06-05T23:34:50.486Z,1686008090.486 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Courier0076.lzma.bak
2023-06-05T23:34:50.486Z,1686008090.486 [DataOverHttps](INFO): SBD MOMSN=18398323
2023-06-05T23:35:08.740Z,1686008108.740 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230605T204550/Express0077.lzma
2023-06-05T23:35:09.750Z,1686008109.750 [DataOverHttps](INFO): Moved sent file to Logs/20230605T204550/Express0077.lzma.bak
2023-06-05T23:35:09.750Z,1686008109.750 [DataOverHttps](INFO): SBD MOMSN=18398326
2023-06-05T23:35:11.359Z,1686008111.359 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T23:35:11.360Z,1686008111.360 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T23:35:11.360Z,1686008111.360 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T23:35:13.777Z,1686008113.777 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-05T23:36:40.678Z,1686008200.678 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:36:56.435Z,1686008216.435 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:37:11.390Z,1686008231.390 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:37:26.338Z,1686008246.338 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:37:41.286Z,1686008261.286 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:37:56.234Z,1686008276.234 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:38:11.586Z,1686008291.586 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:38:26.942Z,1686008306.942 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:38:43.102Z,1686008323.102 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T23:40:12.012Z,1686008412.012 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T23:40:12.012Z,1686008412.012 [Default:CheckIn:C.Wait] Stopped
2023-06-05T23:40:12.012Z,1686008412.012 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T23:40:12.013Z,1686008412.013 [Default:CheckIn:D] Running Loop=1
2023-06-05T23:40:12.424Z,1686008412.424 [Default:CheckIn:D] Stopped
2023-06-05T23:40:12.425Z,1686008412.425 [Default:CheckIn:E] Running Loop=1
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.863070 min 
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn:E] Stopped
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn] Stopped
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn](INFO): Running loop #17
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn] Running Loop=17
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T23:40:12.803Z,1686008412.803 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T23:41:18.180Z,1686008478.180 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-05T23:41:27.184Z,1686008487.184 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-06-05T23:43:00.510Z,1686008580.510 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-06-05T23:43:11.825Z,1686008591.825 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-06-05T23:43:40.508Z,1686008620.508 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-06-05T23:44:05.264Z,1686008645.264 [CommandExec](IMPORTANT): got command quit
2023-06-05T23:44:06.268Z,1686008646.268 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-06-05T23:44:06.268Z,1686008646.268 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:06.268Z,1686008646.268 [CommandExec](INFO): Uninitializing the command executive.
2023-06-05T23:44:06.268Z,1686008646.268 [CommandExec](INFO): Uninitializing the command scheduler.
2023-06-05T23:44:06.269Z,1686008646.269 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.269Z,1686008646.269 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-06-05T23:44:06.269Z,1686008646.269 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-06-05T23:44:06.269Z,1686008646.269 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.270Z,1686008646.270 [NavChartDb](INFO): Join timeout helper Thread ID is 1885
2023-06-05T23:44:06.528Z,1686008646.528 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:06.528Z,1686008646.528 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.532Z,1686008646.532 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-06-05T23:44:06.532Z,1686008646.532 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.532Z,1686008646.532 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1886
2023-06-05T23:44:06.848Z,1686008646.848 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:06.848Z,1686008646.848 [WetLabsBB2FL](INFO): Powering down
2023-06-05T23:44:06.849Z,1686008646.849 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.852Z,1686008646.852 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-06-05T23:44:06.852Z,1686008646.852 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:06.852Z,1686008646.852 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1887
2023-06-05T23:44:07.480Z,1686008647.480 [CTD_Seabird](INFO): Powering down
2023-06-05T23:44:07.492Z,1686008647.492 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:07.492Z,1686008647.492 [CTD_Seabird](INFO): Powering down
2023-06-05T23:44:07.504Z,1686008647.504 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:07.512Z,1686008647.512 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-06-05T23:44:07.512Z,1686008647.512 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:07.512Z,1686008647.512 [Radio_Surface](INFO): Join timeout helper Thread ID is 1888
2023-06-05T23:44:07.648Z,1686008647.648 [Radio_Surface](INFO): Powering down
2023-06-05T23:44:07.649Z,1686008647.649 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:07.649Z,1686008647.649 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:07.660Z,1686008647.660 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-06-05T23:44:07.660Z,1686008647.660 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:07.660Z,1686008647.660 [Onboard](INFO): Join timeout helper Thread ID is 1889
2023-06-05T23:44:08.188Z,1686008648.188 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-06-05T23:44:10.880Z,1686008650.880 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:10.880Z,1686008650.880 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:10.885Z,1686008650.885 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-06-05T23:44:10.885Z,1686008650.885 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:10.885Z,1686008650.885 [DataOverHttps](INFO): Join timeout helper Thread ID is 1890
2023-06-05T23:44:11.200Z,1686008651.200 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:11.200Z,1686008651.200 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.213Z,1686008651.213 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-06-05T23:44:11.213Z,1686008651.213 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.213Z,1686008651.213 [logger](INFO): Join timeout helper Thread ID is 1891
2023-06-05T23:44:11.240Z,1686008651.240 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:11.240Z,1686008651.240 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.253Z,1686008651.253 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-06-05T23:44:11.253Z,1686008651.253 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.253Z,1686008651.253 [CommandLine](INFO): Join timeout helper Thread ID is 1892
2023-06-05T23:44:11.352Z,1686008651.352 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:11.352Z,1686008651.352 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.372Z,1686008651.372 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-06-05T23:44:11.373Z,1686008651.373 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.373Z,1686008651.373 [CommandExec](INFO): Join timeout helper Thread ID is 1893
2023-06-05T23:44:11.374Z,1686008651.374 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-06-05T23:44:11.374Z,1686008651.374 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.375Z,1686008651.375 [controlThread](INFO): Join timeout helper Thread ID is 1894
2023-06-05T23:44:11.540Z,1686008651.540 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T23:44:11.540Z,1686008651.540 [controlThread](DEBUG): Uninitializing ControlThread
2023-06-05T23:44:11.541Z,1686008651.541 [AHRS_M2](INFO): Powering down
2023-06-05T23:44:11.613Z,1686008651.613 [NAL9602](INFO): Powering down
2023-06-05T23:44:11.615Z,1686008651.615 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-06-05T23:44:11.616Z,1686008651.616 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-06-05T23:44:11.617Z,1686008651.617 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-06-05T23:44:11.617Z,1686008651.617 [MissionManager](INFO): Uninitializing Mission Default
2023-06-05T23:44:11.617Z,1686008651.617 [Default] Stopped
2023-06-05T23:44:11.617Z,1686008651.617 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-05T23:44:11.618Z,1686008651.618 [Default:B.GoToSurface] Stopped
2023-06-05T23:44:11.618Z,1686008651.618 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-05T23:44:11.618Z,1686008651.618 [Default:CheckIn] Stopped
2023-06-05T23:44:11.618Z,1686008651.618 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T23:44:11.618Z,1686008651.618 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T23:44:11.621Z,1686008651.621 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-06-05T23:44:11.621Z,1686008651.621 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-06-05T23:44:11.621Z,1686008651.621 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-06-05T23:44:11.622Z,1686008651.622 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-06-05T23:44:11.622Z,1686008651.622 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-06-05T23:44:11.622Z,1686008651.622 [BuoyancyServo](INFO): Powering down
2023-06-05T23:44:11.636Z,1686008651.636 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-06-05T23:44:11.636Z,1686008651.636 [ElevatorServo](INFO): Powering down
2023-06-05T23:44:11.637Z,1686008651.637 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-06-05T23:44:11.637Z,1686008651.637 [MassServo](INFO): Powering down
2023-06-05T23:44:11.638Z,1686008651.638 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-06-05T23:44:11.638Z,1686008651.638 [RudderServo](INFO): Powering down
2023-06-05T23:44:11.639Z,1686008651.639 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2023-06-05T23:44:11.639Z,1686008651.639 [ThrusterServo](INFO): Powering down
2023-06-05T23:44:11.640Z,1686008651.640 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-06-05T23:44:11.640Z,1686008651.640 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-06-05T23:44:11.640Z,1686008651.640 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-06-05T23:44:11.641Z,1686008651.641 [CBIT](DEBUG): Powering off loads.
2023-06-05T23:44:11.652Z,1686008651.652 [CBIT](DEBUG): Disabling WDT.
2023-06-05T23:44:11.664Z,1686008651.664 [CBIT](DEBUG): Opening all GF detection circuits.
2023-06-05T23:44:11.664Z,1686008651.664 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.710Z,1686008651.710 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.713Z,1686008651.713 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.719Z,1686008651.719 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.793Z,1686008651.793 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.796Z,1686008651.796 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.836Z,1686008651.836 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-05T23:44:11.909Z,1686008651.909 [logger ThreadHandler](INFO): Thread cancelled.